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 + tms.tms_cutime) * ticks_to_msec;
 212     now->sys  = (tms.tms_stime + tms.tms_cstime) * 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     getrusage (RUSAGE_CHILDREN, &rusage);
 220     now->user += rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
 221     now->sys  += rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
 222 #endif
 223 #ifdef USE_CLOCK
 224     now->user = clock () * clocks_to_msec;
 225 #endif
 226   }
 227 }
 228
 229 /* Add the difference between STOP_TIME and START_TIME to TIMER.  */
 230
 231 static void
 232 timevar_accumulate (timer, start_time, stop_time)
 233   struct timevar_time_def *timer;
 234   struct timevar_time_def *start_time;
 235   struct timevar_time_def *stop_time;
 236 {
 237   timer->user += stop_time->user - start_time->user;
 238   timer->sys += stop_time->sys - start_time->sys;
 239   timer->wall += stop_time->wall - start_time->wall;
 240 }
 241
 242 /* Initialize timing variables.  */
 243
 244 void
 245 init_timevar ()
 246 {
 247   if (!TIMEVAR_ENABLE)
 248     return;
 249
 250   /* Zero all elapsed times.  */
 251   memset ((void *) timevars, 0, sizeof (timevars));
 252
 253   /* Initialize the names of timing variables.  */
 254 #define DEFTIMEVAR(identifier__, name__) \
 255   timevars[identifier__].name = name__;
 256 #include "timevar.def"
 257 #undef DEFTIMEVAR
 258
 259 #ifdef USE_TIMES
 260   ticks_to_msec = TICKS_TO_MSEC;
 261 #endif
 262 #ifdef USE_CLOCK
 263   clocks_to_msec = CLOCKS_TO_MSEC;
 264 #endif
 265 }
 266
 267 /* Push TIMEVAR onto the timing stack.  No further elapsed time is
 268    attributed to the previous topmost timing variable on the stack;
 269    subsequent elapsed time is attributed to TIMEVAR, until it is
 270    popped or another element is pushed on top.
 271
 272    TIMEVAR cannot be running as a standalone timer.  */
 273
 274 void
 275 timevar_push (timevar)
 276      timevar_id_t timevar;
 277 {
 278   struct timevar_def *tv = &timevars[timevar];
 279   struct timevar_stack_def *context;
 280   struct timevar_time_def now;
 281
 282   if (!TIMEVAR_ENABLE)
 283     return;
 284
 285   /* Mark this timing variable as used.  */
 286   tv->used = 1;
 287
 288   /* Can't push a standalone timer.  */
 289   if (tv->standalone)
 290     abort ();
 291
 292   /* What time is it?  */
 293   get_time (&now);
 294
 295   /* If the stack isn't empty, attribute the current elapsed time to
 296      the old topmost element.  */
 297   if (stack)
 298     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 299
 300   /* Reset the start time; from now on, time is attributed to
 301      TIMEVAR.  */
 302   start_time = now;
 303
 304   /* See if we have a previously-allocated stack instance.  If so,
 305      take it off the list.  If not, malloc a new one.  */
 306   if (unused_stack_instances != NULL)
 307     {
 308       context = unused_stack_instances;
 309       unused_stack_instances = unused_stack_instances->next;
 310     }
 311   else
 312     context = (struct timevar_stack_def *)
 313       xmalloc (sizeof (struct timevar_stack_def));
 314
 315   /* Fill it in and put it on the stack.  */
 316   context->timevar = tv;
 317   context->next = stack;
 318   stack = context;
 319 }
 320
 321 /* Pop the topmost timing variable element off the timing stack.  The
 322    popped variable must be TIMEVAR.  Elapsed time since the that
 323    element was pushed on, or since it was last exposed on top of the
 324    stack when the element above it was popped off, is credited to that
 325    timing variable.  */
 326
 327 void
 328 timevar_pop (timevar)
 329      timevar_id_t timevar;
 330 {
 331   struct timevar_time_def now;
 332   struct timevar_stack_def *popped = stack;
 333
 334   if (!TIMEVAR_ENABLE)
 335     return;
 336
 337   if (&timevars[timevar] != stack->timevar)
 338     abort ();
 339
 340   /* What time is it?  */
 341   get_time (&now);
 342
 343   /* Attribute the elapsed time to the element we're popping.  */
 344   timevar_accumulate (&popped->timevar->elapsed, &start_time, &now);
 345
 346   /* Reset the start time; from now on, time is attributed to the
 347      element just exposed on the stack.  */
 348   start_time = now;
 349
 350   /* Take the item off the stack.  */
 351   stack = stack->next;
 352
 353   /* Don't delete the stack element; instead, add it to the list of
 354      unused elements for later use.  */
 355   popped->next = unused_stack_instances;
 356   unused_stack_instances = popped;
 357 }
 358
 359 /* Start timing TIMEVAR independently of the timing stack.  Elapsed
 360    time until timevar_stop is called for the same timing variable is
 361    attributed to TIMEVAR.  */
 362
 363 void
 364 timevar_start (timevar)
 365      timevar_id_t timevar;
 366 {
 367   struct timevar_def *tv = &timevars[timevar];
 368
 369   if (!TIMEVAR_ENABLE)
 370     return;
 371
 372   /* Mark this timing variable as used.  */
 373   tv->used = 1;
 374
 375   /* Don't allow the same timing variable to be started more than
 376      once.  */
 377   if (tv->standalone)
 378     abort ();
 379   tv->standalone = 1;
 380
 381   get_time (&tv->start_time);
 382 }
 383
 384 /* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
 385    is attributed to it.  */
 386
 387 void
 388 timevar_stop (timevar)
 389      timevar_id_t timevar;
 390 {
 391   struct timevar_def *tv = &timevars[timevar];
 392   struct timevar_time_def now;
 393
 394   if (!TIMEVAR_ENABLE)
 395     return;
 396
 397   /* TIMEVAR must have been started via timevar_start.  */
 398   if (!tv->standalone)
 399     abort ();
 400
 401   get_time (&now);
 402   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
 403 }
 404
 405 /* Fill the elapsed time for TIMEVAR into ELAPSED.  Returns
 406    update-to-date information even if TIMEVAR is currently running.  */
 407
 408 void
 409 timevar_get (timevar, elapsed)
 410      timevar_id_t timevar;
 411      struct timevar_time_def *elapsed;
 412 {
 413   struct timevar_def *tv = &timevars[timevar];
 414   struct timevar_time_def now;
 415
 416   *elapsed = tv->elapsed;
 417
 418   /* Is TIMEVAR currently running as a standalone timer?  */
 419   if (tv->standalone)
 420     {
 421       get_time (&now);
 422       timevar_accumulate (elapsed, &tv->start_time, &now);
 423     }
 424   /* Or is TIMEVAR at the top of the timer stack?  */
 425   else if (stack->timevar == tv)
 426     {
 427       get_time (&now);
 428       timevar_accumulate (elapsed, &start_time, &now);
 429     }
 430 }
 431
 432 /* Summarize timing variables to FP.  The timing variable TV_TOTAL has
 433    a special meaning -- it's considered to be the total elapsed time,
 434    for normalizing the others, and is displayed last.  */
 435
 436 void
 437 timevar_print (fp)
 438      FILE *fp;
 439 {
 440   /* Only print stuff if we have some sort of time information.  */
 441 #if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
 442   unsigned int /* timevar_id_t */ id;
 443   struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
 444   struct timevar_time_def now;
 445
 446   if (!TIMEVAR_ENABLE)
 447     return;
 448
 449   /* Update timing information in case we're calling this from GDB.  */
 450
 451   if (fp == 0)
 452     fp = stderr;
 453
 454   /* What time is it?  */
 455   get_time (&now);
 456
 457   /* If the stack isn't empty, attribute the current elapsed time to
 458      the old topmost element.  */
 459   if (stack)
 460     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 461
 462   /* Reset the start time; from now on, time is attributed to
 463      TIMEVAR.  */
 464   start_time = now;
 465
 466   fputs (_("\nExecution times (seconds)\n"), fp);
 467   for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
 468     {
 469       struct timevar_def *tv = &timevars[(timevar_id_t) id];
 470       const float tiny = 5e-3;
 471
 472       /* Don't print the total execution time here; that goes at the
 473          end.  */
 474       if ((timevar_id_t) id == TV_TOTAL)
 475         continue;
 476
 477       /* Don't print timing variables that were never used.  */
 478       if (!tv->used)
 479         continue;
 480
 481       /* Don't print timing variables if we're going to get a row of
 482          zeroes.  */
 483       if (tv->elapsed.user < tiny
 484           && tv->elapsed.sys < tiny
 485           && tv->elapsed.wall < tiny)
 486         continue;
 487
 488       /* The timing variable name.  */
 489       fprintf (fp, " %-22s:", tv->name);
 490
 491 #ifdef HAVE_USER_TIME
 492       /* Print user-mode time for this process.  */
 493       fprintf (fp, "%7.2f (%2.0f%%) usr",
 494                tv->elapsed.user,
 495                (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
 496 #endif /* HAVE_USER_TIME */
 497
 498 #ifdef HAVE_SYS_TIME
 499       /* Print system-mode time for this process.  */
 500       fprintf (fp, "%7.2f (%2.0f%%) sys",
 501                tv->elapsed.sys,
 502                (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
 503 #endif /* HAVE_SYS_TIME */
 504
 505 #ifdef HAVE_WALL_TIME
 506       /* Print wall clock time elapsed.  */
 507       fprintf (fp, "%7.2f (%2.0f%%) wall",
 508                tv->elapsed.wall,
 509                (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
 510 #endif /* HAVE_WALL_TIME */
 511
 512       putc ('\n', fp);
 513     }
 514
 515   /* Print total time.  */
 516   fputs (_(" TOTAL                 :"), fp);
 517 #ifdef HAVE_USER_TIME
 518   fprintf (fp, "%7.2f          ", total->user);
 519 #endif
 520 #ifdef HAVE_SYS_TIME
 521   fprintf (fp, "%7.2f          ", total->sys);
 522 #endif
 523 #ifdef HAVE_WALL_TIME
 524   fprintf (fp, "%7.2f\n", total->wall);
 525 #endif
 526
 527 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 528           || defined (HAVE_WALL_TIME) */
 529 }
 530
 531 /* Returns time (user + system) used so far by the compiler process,
 532    in microseconds.  */
 533
 534 long
 535 get_run_time ()
 536 {
 537   struct timevar_time_def total_elapsed;
 538   timevar_get (TV_TOTAL, &total_elapsed);
 539   return total_elapsed.user + total_elapsed.sys;
 540 }
 541
 542 /* Prints a message to stderr stating that time elapsed in STR is
 543    TOTAL (given in microseconds).  */
 544
 545 void
 546 print_time (str, total)
 547      const char *str;
 548      long total;
 549 {
 550   long all_time = get_run_time ();
 551   fprintf (stderr,
 552            _("time in %s: %ld.%06ld (%ld%%)\n"),
 553            str, total / 1000000, total % 1000000,
 554            all_time == 0 ? 0
 555            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
 556 }