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     abort ();
 323
 324   /* What time is it?  */
 325   get_time (&now);
 326
 327   /* Attribute the elapsed time to the element we're popping.  */
 328   timevar_accumulate (&popped->timevar->elapsed, &start_time, &now);
 329
 330   /* Reset the start time; from now on, time is attributed to the
 331      element just exposed on the stack.  */
 332   start_time = now;
 333
 334   /* Take the item off the stack.  */
 335   stack = stack->next;
 336
 337   /* Don't delete the stack element; instead, add it to the list of
 338      unused elements for later use.  */
 339   popped->next = unused_stack_instances;
 340   unused_stack_instances = popped;
 341 }
 342
 343 /* Start timing TIMEVAR independently of the timing stack.  Elapsed
 344    time until timevar_stop is called for the same timing variable is
 345    attributed to TIMEVAR.  */
 346
 347 void
 348 timevar_start (timevar)
 349      timevar_id_t timevar;
 350 {
 351   struct timevar_def *tv = &timevars[timevar];
 352
 353   if (!TIMEVAR_ENABLE)
 354     return;
 355
 356   /* Mark this timing variable as used.  */
 357   tv->used = 1;
 358
 359   /* Don't allow the same timing variable to be started more than
 360      once.  */
 361   if (tv->standalone)
 362     abort ();
 363   tv->standalone = 1;
 364
 365   get_time (&tv->start_time);
 366 }
 367
 368 /* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
 369    is attributed to it.  */
 370
 371 void
 372 timevar_stop (timevar)
 373      timevar_id_t timevar;
 374 {
 375   struct timevar_def *tv = &timevars[timevar];
 376   struct timevar_time_def now;
 377
 378   if (!TIMEVAR_ENABLE)
 379     return;
 380
 381   /* TIMEVAR must have been started via timevar_start.  */
 382   if (!tv->standalone)
 383     abort ();
 384
 385   get_time (&now);
 386   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
 387 }
 388
 389 /* Fill the elapsed time for TIMEVAR into ELAPSED.  Returns
 390    update-to-date information even if TIMEVAR is currently running.  */
 391
 392 void
 393 timevar_get (timevar, elapsed)
 394      timevar_id_t timevar;
 395      struct timevar_time_def *elapsed;
 396 {
 397   struct timevar_def *tv = &timevars[timevar];
 398   struct timevar_time_def now;
 399
 400   *elapsed = tv->elapsed;
 401
 402   /* Is TIMEVAR currently running as a standalone timer?  */
 403   if (tv->standalone)
 404     {
 405       get_time (&now);
 406       timevar_accumulate (elapsed, &tv->start_time, &now);
 407     }
 408   /* Or is TIMEVAR at the top of the timer stack?  */
 409   else if (stack->timevar == tv)
 410     {
 411       get_time (&now);
 412       timevar_accumulate (elapsed, &start_time, &now);
 413     }
 414 }
 415
 416 /* Summarize timing variables to FP.  The timing variable TV_TOTAL has
 417    a special meaning -- it's considered to be the total elapsed time,
 418    for normalizing the others, and is displayed last.  */
 419
 420 void
 421 timevar_print (fp)
 422      FILE *fp;
 423 {
 424   /* Only print stuff if we have some sort of time information.  */
 425 #if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
 426   unsigned int /* timevar_id_t */ id;
 427   struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
 428   struct timevar_time_def now;
 429
 430   if (!TIMEVAR_ENABLE)
 431     return;
 432
 433   /* Update timing information in case we're calling this from GDB.  */
 434
 435   if (fp == 0)
 436     fp = stderr;
 437
 438   /* What time is it?  */
 439   get_time (&now);
 440
 441   /* If the stack isn't empty, attribute the current elapsed time to
 442      the old topmost element.  */
 443   if (stack)
 444     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 445
 446   /* Reset the start time; from now on, time is attributed to
 447      TIMEVAR.  */
 448   start_time = now;
 449
 450   fputs (_("\nExecution times (seconds)\n"), fp);
 451   for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
 452     {
 453       struct timevar_def *tv = &timevars[(timevar_id_t) id];
 454       const double tiny = 5e-3;
 455
 456       /* Don't print the total execution time here; that goes at the
 457          end.  */
 458       if ((timevar_id_t) id == TV_TOTAL)
 459         continue;
 460
 461       /* Don't print timing variables that were never used.  */
 462       if (!tv->used)
 463         continue;
 464
 465       /* Don't print timing variables if we're going to get a row of
 466          zeroes.  */
 467       if (tv->elapsed.user < tiny
 468           && tv->elapsed.sys < tiny
 469           && tv->elapsed.wall < tiny)
 470         continue;
 471
 472       /* The timing variable name.  */
 473       fprintf (fp, " %-22s:", tv->name);
 474
 475 #ifdef HAVE_USER_TIME
 476       /* Print user-mode time for this process.  */
 477       fprintf (fp, "%7.2f (%2.0f%%) usr",
 478                tv->elapsed.user,
 479                (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
 480 #endif /* HAVE_USER_TIME */
 481
 482 #ifdef HAVE_SYS_TIME
 483       /* Print system-mode time for this process.  */
 484       fprintf (fp, "%7.2f (%2.0f%%) sys",
 485                tv->elapsed.sys,
 486                (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
 487 #endif /* HAVE_SYS_TIME */
 488
 489 #ifdef HAVE_WALL_TIME
 490       /* Print wall clock time elapsed.  */
 491       fprintf (fp, "%7.2f (%2.0f%%) wall",
 492                tv->elapsed.wall,
 493                (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
 494 #endif /* HAVE_WALL_TIME */
 495
 496       putc ('\n', fp);
 497     }
 498
 499   /* Print total time.  */
 500   fputs (_(" TOTAL                 :"), fp);
 501 #ifdef HAVE_USER_TIME
 502   fprintf (fp, "%7.2f          ", total->user);
 503 #endif
 504 #ifdef HAVE_SYS_TIME
 505   fprintf (fp, "%7.2f          ", total->sys);
 506 #endif
 507 #ifdef HAVE_WALL_TIME
 508   fprintf (fp, "%7.2f\n", total->wall);
 509 #endif
 510
 511 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 512           || defined (HAVE_WALL_TIME) */
 513 }
 514
 515 /* Returns time (user + system) used so far by the compiler process,
 516    in microseconds.  */
 517
 518 long
 519 get_run_time ()
 520 {
 521   struct timevar_time_def total_elapsed;
 522   timevar_get (TV_TOTAL, &total_elapsed);
 523   return total_elapsed.user + total_elapsed.sys;
 524 }
 525
 526 /* Prints a message to stderr stating that time elapsed in STR is
 527    TOTAL (given in microseconds).  */
 528
 529 void
 530 print_time (str, total)
 531      const char *str;
 532      long total;
 533 {
 534   long all_time = get_run_time ();
 535   fprintf (stderr,
 536            _("time in %s: %ld.%06ld (%ld%%)\n"),
 537            str, total / 1000000, total % 1000000,
 538            all_time == 0 ? 0
 539            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
 540 }