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