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