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 GNU CC.
   6
   7    GNU CC is free software; you can redistribute it and/or modify
   8    it 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    GNU CC is distributed in the hope that it will be useful,
  13    but WITHOUT ANY WARRANTY; without even the implied warranty of
  14    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  15    GNU General Public License for more details.
  16
  17    You should have received a copy of the GNU General Public License
  18    along with GNU CC; see the file COPYING.  If not, write to
  19    the Free Software Foundation, 59 Temple Place - Suite 330,
  20    Boston, MA 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 #define TICKS_TO_USEC (1000000 / TICKS_PER_SECOND)
  78 #define CLOCKS_TO_USEC (1000000 / CLOCKS_PER_SEC)
  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 #include "flags.h"
 101 #include "timevar.h"
 102
 103 /* See timevar.h for an explanation of timing variables.  */
 104
 105 /* This macro evaluates to non-zero if timing variables are enabled. */
 106 #define TIMEVAR_ENABLE (time_report)
 107
 108 /* A timing variable.  */
 109
 110 struct timevar_def
 111 {
 112   /* Elapsed time for this variable.  */
 113   struct timevar_time_def elapsed;
 114
 115   /* If this variable is timed independently of the timing stack,
 116      using timevar_start, this contains the start time.  */
 117   struct timevar_time_def start_time;
 118
 119   /* The name of this timing variable.  */
 120   const char *name;
 121
 122   /* Non-zero if this timing variable is running as a standalone
 123      timer.  */
 124   unsigned standalone : 1;
 125
 126   /* Non-zero if this timing variable was ever started or pushed onto
 127      the timing stack.  */
 128   unsigned used : 1;
 129 };
 130
 131 /* An element on the timing stack.  Elapsed time is attributed to the
 132    topmost timing variable on the stack.  */
 133
 134 struct timevar_stack_def
 135 {
 136   /* The timing variable at this stack level.  */
 137   struct timevar_def *timevar;
 138
 139   /* The next lower timing variable context in the stack.  */
 140   struct timevar_stack_def *next;
 141 };
 142
 143 /* Declared timing variables.  Constructed from the contents of
 144    timevar.def.  */
 145 static struct timevar_def timevars[TIMEVAR_LAST];
 146
 147 /* The top of the timing stack.  */
 148 static struct timevar_stack_def *stack;
 149
 150 /* A list of unused (i.e. allocated and subsequently popped)
 151    timevar_stack_def instances.  */
 152 static struct timevar_stack_def *unused_stack_instances;
 153
 154 /* The time at which the topmost element on the timing stack was
 155    pushed.  Time elapsed since then is attributed to the topmost
 156    element.  */
 157 static struct timevar_time_def start_time;
 158
 159 static void get_time
 160   PARAMS ((struct timevar_time_def *));
 161 static void timevar_accumulate
 162   PARAMS ((struct timevar_time_def *, struct timevar_time_def *,
 163            struct timevar_time_def *));
 164
 165 /* Fill the current times into TIME.  The definition of this function
 166    also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
 167    HAVA_WALL_TIME macros.  */
 168
 169 static void
 170 get_time (now)
 171      struct timevar_time_def *now;
 172 {
 173   now->user = 0;
 174   now->sys  = 0;
 175   now->wall = 0;
 176
 177   if (!TIMEVAR_ENABLE)
 178     return;
 179
 180   {
 181 #ifdef USE_TIMES
 182     /* libc is very likely to have snuck a call to sysconf() into one
 183        of the underlying constants, and that can make system calls, so
 184        we have to precompute the value.  Whose wonderful idea was it
 185        to make all those _constants_ variable at run time, anyway?  */
 186     static int ticks_to_usec;
 187     struct tms tms;
 188     if (ticks_to_usec == 0)
 189       ticks_to_usec = TICKS_TO_USEC;
 190
 191     now->wall = times (&tms) * ticks_to_usec;
 192     now->user = tms.tms_utime * ticks_to_usec;
 193     now->sys = tms.tms_stime * ticks_to_usec;
 194 #endif
 195 #ifdef USE_GETRUSAGE
 196     struct rusage rusage;
 197     getrusage (RUSAGE_SELF, &rusage);
 198     now->user
 199       = rusage.ru_utime.tv_sec * 1000000 + rusage.ru_utime.tv_usec;
 200     now->sys
 201       = rusage.ru_stime.tv_sec * 1000000 + rusage.ru_stime.tv_usec;
 202 #endif
 203 #ifdef USE_CLOCK
 204     static int clocks_to_usec;
 205     if (clocks_to_usec == 0)
 206       clocks_to_usec = CLOCKS_TO_USEC;
 207     now->user = clock () * clocks_to_usec;
 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(identifer__, name__) \
 238   timevars[identifer__].name = name__;
 239 #include "timevar.def"
 240 #undef DEFTIMEVAR
 241 }
 242
 243 /* Push TIMEVAR onto the timing stack.  No further elapsed time is
 244    attributed to the previous topmost timing variable on the stack;
 245    subsequent elapsed time is attributed to TIMEVAR, until it is
 246    popped or another element is pushed on top.
 247
 248    TIMEVAR cannot be running as a standalone timer.  */
 249
 250 void
 251 timevar_push (timevar)
 252      timevar_id_t timevar;
 253 {
 254   struct timevar_def *tv = &timevars[timevar];
 255   struct timevar_stack_def *context;
 256   struct timevar_time_def now;
 257
 258   if (!TIMEVAR_ENABLE)
 259     return;
 260
 261   /* Mark this timing variable as used.  */
 262   tv->used = 1;
 263
 264   /* Can't push a standalone timer.  */
 265   if (tv->standalone)
 266     abort ();
 267
 268   /* What time is it?  */
 269   get_time (&now);
 270
 271   /* If the stack isn't empty, attribute the current elapsed time to
 272      the old topmost element.  */
 273   if (stack)
 274     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 275
 276   /* Reset the start time; from now on, time is attributed to
 277      TIMEVAR. */
 278   start_time = now;
 279
 280   /* See if we have a previously-allocated stack instance.  If so,
 281      take it off the list.  If not, malloc a new one.  */
 282   if (unused_stack_instances != NULL)
 283     {
 284       context = unused_stack_instances;
 285       unused_stack_instances = unused_stack_instances->next;
 286     }
 287   else
 288     context = (struct timevar_stack_def *)
 289       xmalloc (sizeof (struct timevar_stack_def));
 290
 291   /* Fill it in and put it on the stack.  */
 292   context->timevar = tv;
 293   context->next = stack;
 294   stack = context;
 295 }
 296
 297 /* Pop the topmost timing variable element off the timing stack.  The
 298    popped variable must be TIMEVAR.  Elapsed time since the that
 299    element was pushed on, or since it was last exposed on top of the
 300    stack when the element above it was popped off, is credited to that
 301    timing variable.  */
 302
 303 void
 304 timevar_pop (timevar)
 305      timevar_id_t timevar;
 306 {
 307   struct timevar_time_def now;
 308   struct timevar_stack_def *popped = stack;
 309
 310   if (!TIMEVAR_ENABLE)
 311     return;
 312
 313   if (&timevars[timevar] != stack->timevar)
 314     abort ();
 315
 316   /* What time is it?  */
 317   get_time (&now);
 318
 319   /* Attribute the elapsed time to the element we're popping.  */
 320   timevar_accumulate (&popped->timevar->elapsed, &start_time, &now);
 321
 322   /* Reset the start time; from now on, time is attributed to the
 323      element just exposed on the stack.  */
 324   start_time = now;
 325
 326   /* Take the item off the stack.  */
 327   stack = stack->next;
 328
 329   /* Don't delete the stack element; instead, add it to the list of
 330      unused elements for later use.  */
 331   popped->next = unused_stack_instances;
 332   unused_stack_instances = popped;
 333 }
 334
 335 /* Start timing TIMEVAR independently of the timing stack.  Elapsed
 336    time until timevar_stop is called for the same timing variable is
 337    attributed to TIMEVAR.  */
 338
 339 void
 340 timevar_start (timevar)
 341      timevar_id_t timevar;
 342 {
 343   struct timevar_def *tv = &timevars[timevar];
 344
 345   if (!TIMEVAR_ENABLE)
 346     return;
 347
 348   /* Mark this timing variable as used.  */
 349   tv->used = 1;
 350
 351   /* Don't allow the same timing variable to be started more than
 352      once.  */
 353   if (tv->standalone)
 354     abort ();
 355   tv->standalone = 1;
 356
 357   get_time (&tv->start_time);
 358 }
 359
 360 /* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
 361    is attributed to it.  */
 362
 363 void
 364 timevar_stop (timevar)
 365      timevar_id_t timevar;
 366 {
 367   struct timevar_def *tv = &timevars[timevar];
 368   struct timevar_time_def now;
 369
 370   if (!TIMEVAR_ENABLE)
 371     return;
 372
 373   /* TIMEVAR must have been started via timevar_start.  */
 374   if (!tv->standalone)
 375     abort ();
 376
 377   get_time (&now);
 378   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
 379 }
 380
 381 /* Fill the elapsed time for TIMEVAR into ELAPSED.  Returns
 382    update-to-date information even if TIMEVAR is currently running.  */
 383
 384 void
 385 timevar_get (timevar, elapsed)
 386      timevar_id_t timevar;
 387      struct timevar_time_def *elapsed;
 388 {
 389   struct timevar_def *tv = &timevars[timevar];
 390   struct timevar_time_def now;
 391
 392   *elapsed = tv->elapsed;
 393
 394   /* Is TIMEVAR currently running as a standalone timer?  */
 395   if (tv->standalone)
 396     {
 397       get_time (&now);
 398       timevar_accumulate (elapsed, &tv->start_time, &now);
 399     }
 400   /* Or is TIMEVAR at the top of the timer stack?  */
 401   else if (stack->timevar == tv)
 402     {
 403       get_time (&now);
 404       timevar_accumulate (elapsed, &start_time, &now);
 405     }
 406 }
 407
 408 /* Summarize timing variables to FP.  The timing variable TV_TOTAL has
 409    a special meaning -- it's considered to be the total elapsed time,
 410    for normalizing the others, and is displayed last.  */
 411
 412 void
 413 timevar_print (fp)
 414      FILE *fp;
 415 {
 416   /* Only print stuff if we have some sort of time information.  */
 417 #if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
 418   unsigned int /* timevar_id_t */ id;
 419   struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
 420   struct timevar_time_def now;
 421
 422   if (!TIMEVAR_ENABLE)
 423     return;
 424
 425   /* Update timing information in case we're calling this from GDB.  */
 426
 427   if (fp == 0)
 428     fp = stderr;
 429
 430   /* What time is it?  */
 431   get_time (&now);
 432
 433   /* If the stack isn't empty, attribute the current elapsed time to
 434      the old topmost element.  */
 435   if (stack)
 436     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 437
 438   /* Reset the start time; from now on, time is attributed to
 439      TIMEVAR. */
 440   start_time = now;
 441
 442   fprintf (fp, _("\nExecution times (seconds)\n"));
 443   for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
 444     {
 445       struct timevar_def *tv = &timevars[(timevar_id_t) id];
 446
 447       /* Don't print the total execution time here; that goes at the
 448          end.  */
 449       if ((timevar_id_t) id == TV_TOTAL)
 450         continue;
 451
 452       /* Don't print timing variables that were never used.  */
 453       if (!tv->used)
 454         continue;
 455
 456       /* The timing variable name.  */
 457       fprintf (fp, " %-22s:", tv->name);
 458
 459 #ifdef HAVE_USER_TIME
 460       /* Print user-mode time for this process.  */
 461       fprintf (fp, "%4ld.%02ld (%2.0f%%) usr",
 462                tv->elapsed.user / 1000000,
 463                (tv->elapsed.user % 1000000) / 10000,
 464                (total->user == 0) ? 0.0
 465                : (100.0 * tv->elapsed.user / (double) total->user));
 466 #endif /* HAVE_USER_TIME */
 467
 468 #ifdef HAVE_SYS_TIME
 469       /* Print system-mode time for this process.  */
 470       fprintf (fp, "%4ld.%02ld (%2.0f%%) sys",
 471                tv->elapsed.sys / 1000000,
 472                (tv->elapsed.sys % 1000000) / 10000,
 473                (total->sys == 0) ? 0.0
 474                : (100.0 * tv->elapsed.sys / (double) total->sys));
 475 #endif /* HAVE_SYS_TIME */
 476
 477 #ifdef HAVE_WALL_TIME
 478       /* Print wall clock time elapsed.  */
 479       fprintf (fp, "%4ld.%02ld (%2.0f%%) wall",
 480                tv->elapsed.wall / 1000000,
 481                (tv->elapsed.wall % 1000000) / 10000,
 482                (total->wall == 0) ? 0.0
 483                : (100.0 * tv->elapsed.wall / (double) total->wall));
 484 #endif /* HAVE_WALL_TIME */
 485
 486       fprintf (fp, "\n");
 487     }
 488
 489   /* Print total time.  */
 490   fprintf (fp, _(" TOTAL                 :"));
 491 #ifdef HAVE_USER_TIME
 492   fprintf (fp, "%4ld.%02ld          ",
 493            total->user / 1000000, (total->user % 1000000) / 10000);
 494 #endif
 495 #ifdef HAVE_SYS_TIME
 496   fprintf (fp, "%4ld.%02ld          ",
 497            total->sys  / 1000000, (total->sys  % 1000000) / 10000);
 498 #endif
 499 #ifdef HAVE_WALL_TIME
 500   fprintf (fp, "%4ld.%02ld\n",
 501            total->wall / 1000000, (total->wall % 1000000) / 10000);
 502 #endif
 503
 504 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 505           || defined (HAVE_WALL_TIME) */
 506 }
 507
 508 /* Returns time (user + system) used so far by the compiler process,
 509    in microseconds.  */
 510
 511 long
 512 get_run_time ()
 513 {
 514   struct timevar_time_def total_elapsed;
 515   timevar_get (TV_TOTAL, &total_elapsed);
 516   return total_elapsed.user + total_elapsed.sys;
 517 }
 518
 519 /* Prints a message to stderr stating that time elapsed in STR is
 520    TOTAL (given in microseconds).  */
 521
 522 void
 523 print_time (str, total)
 524      const char *str;
 525      long total;
 526 {
 527   long all_time = get_run_time ();
 528   fprintf (stderr,
 529            _("time in %s: %ld.%06ld (%ld%%)\n"),
 530            str, total / 1000000, total % 1000000,
 531            all_time == 0 ? 0
 532            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
 533 }