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