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
  30 #ifdef HAVE_SYS_RESOURCE_H
  31 #include <sys/resource.h>
  32 #endif
  33 #ifdef NEED_DECLARATION_GETRUSAGE
  34 extern int getrusage PARAMS ((int, struct rusage *));
  35 #endif
  36
  37 #include "flags.h"
  38 #include "timevar.h"
  39
  40 /* See timevar.h for an explanation of timing variables.  */
  41
  42 /* This macro evaluates to non-zero if timing variables are enabled. */
  43 #define TIMEVAR_ENABLE (!quiet_flag)
  44
  45 /* A timing variable.  */
  46
  47 struct timevar_def
  48 {
  49   /* Elapsed time for this variable.  */
  50   struct timevar_time_def elapsed;
  51
  52   /* If this variable is timed independently of the timing stack,
  53      using timevar_start, this contains the start time.  */
  54   struct timevar_time_def start_time;
  55
  56   /* The name of this timing variable.  */
  57   const char *name;
  58
  59   /* Non-zero if this timing variable is running as a standalone
  60      timer.  */
  61   unsigned standalone : 1;
  62
  63   /* Non-zero if this timing variable was ever started or pushed onto
  64      the timing stack.  */
  65   unsigned used : 1;
  66 };
  67
  68 /* An element on the timing stack.  Elapsed time is attributed to the
  69    topmost timing variable on the stack.  */
  70
  71 struct timevar_stack_def
  72 {
  73   /* The timing variable at this stack level.  */
  74   struct timevar_def *timevar;
  75
  76   /* The next lower timing variable context in the stack.  */
  77   struct timevar_stack_def *next;
  78 };
  79
  80 /* Declared timing variables.  Constructed from the contents of
  81    timevar.def.  */
  82 static struct timevar_def timevars[TIMEVAR_LAST];
  83
  84 /* The top of the timing stack.  */
  85 static struct timevar_stack_def *stack;
  86
  87 /* A list of unused (i.e. allocated and subsequently popped)
  88    timevar_stack_def instances.  */
  89 static struct timevar_stack_def *unused_stack_instances;
  90
  91 /* The time at which the topmost element on the timing stack was
  92    pushed.  Time elapsed since then is attributed to the topmost
  93    element.  */
  94 static struct timevar_time_def start_time;
  95
  96 static void get_time
  97   PARAMS ((struct timevar_time_def *));
  98 static void timevar_add
  99   PARAMS ((struct timevar_time_def *, struct timevar_time_def *));
 100 static void timevar_accumulate
 101   PARAMS ((struct timevar_time_def *, struct timevar_time_def *,
 102            struct timevar_time_def *));
 103
 104 /* Fill the current times into TIME.  The definition of this function
 105    also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
 106    HAVA_WALL_TIME macros.  */
 107
 108 static void
 109 get_time (now)
 110      struct timevar_time_def *now;
 111 {
 112   now->user = 0;
 113   now->sys  = 0;
 114   now->wall = 0;
 115
 116   if (!TIMEVAR_ENABLE)
 117     return;
 118
 119 #ifdef __BEOS__
 120   /* Nothing.  */
 121 #else /* not BeOS */
 122 #if defined (_WIN32) && !defined (__CYGWIN__)
 123   if (clock () >= 0)
 124     now->user = clock () * 1000;
 125 #define HAVE_USER_TIME
 126
 127 #else /* not _WIN32 */
 128 #ifdef _SC_CLK_TCK
 129   {
 130     static int tick;
 131     struct tms tms;
 132     if (tick == 0)
 133       tick = 1000000 / sysconf (_SC_CLK_TCK);
 134     now->wall = times (&tms) * tick;
 135     now->user = tms.tms_utime * tick;
 136     now->sys = tms.tms_stime * tick;
 137   }
 138 #define HAVE_USER_TIME
 139 #define HAVE_SYS_TIME
 140 #define HAVE_WALL_TIME
 141
 142 #else
 143 #ifdef USG
 144   {
 145     struct tms tms;
 146 #   if HAVE_SYSCONF && defined _SC_CLK_TCK
 147 #    define TICKS_PER_SECOND sysconf (_SC_CLK_TCK) /* POSIX 1003.1-1996 */
 148 #   else
 149 #    ifdef CLK_TCK
 150 #     define TICKS_PER_SECOND CLK_TCK /* POSIX 1003.1-1988; obsolescent */
 151 #    else
 152 #     define TICKS_PER_SECOND HZ /* traditional UNIX */
 153 #    endif
 154 #   endif
 155     now->wall = times (&tms) * (1000000 / TICKS_PER_SECOND);
 156     now->user = tms.tms_utime * (1000000 / TICKS_PER_SECOND);
 157     now->sys = tms.tms_stime * (1000000 / TICKS_PER_SECOND);
 158   }
 159 #define HAVE_USER_TIME
 160 #define HAVE_SYS_TIME
 161 #define HAVE_WALL_TIME
 162
 163 #else
 164 #ifndef VMS
 165   {
 166     struct rusage rusage;
 167     getrusage (0, &rusage);
 168     now->user
 169       = rusage.ru_utime.tv_sec * 1000000 + rusage.ru_utime.tv_usec;
 170     now->sys
 171       = rusage.ru_stime.tv_sec * 1000000 + rusage.ru_stime.tv_usec;
 172   }
 173 #define HAVE_USER_TIME
 174 #define HAVE_SYS_TIME
 175
 176 #else /* VMS */
 177   {
 178     struct
 179       {
 180         int proc_user_time;
 181         int proc_system_time;
 182         int child_user_time;
 183         int child_system_time;
 184       } vms_times;
 185     now->wall = times ((void *) &vms_times) * 10000;
 186     now->user = vms_times.proc_user_time * 10000;
 187     now->sys = vms_times.proc_system_time * 10000;
 188   }
 189 #define HAVE_USER_TIME
 190 #define HAVE_SYS_TIME
 191 #define HAVE_WALL_TIME
 192
 193 #endif  /* VMS */
 194 #endif  /* USG */
 195 #endif  /* _SC_CLK_TCK */
 196 #endif  /* _WIN32 */
 197 #endif  /* __BEOS__ */
 198 }
 199
 200 /* Add ELAPSED to TIMER.  */
 201
 202 static void
 203 timevar_add (timer, elapsed)
 204      struct timevar_time_def *timer;
 205      struct timevar_time_def *elapsed;
 206 {
 207   timer->user += elapsed->user;
 208   timer->sys += elapsed->sys;
 209   timer->wall += elapsed->wall;
 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
 391   *elapsed = tv->elapsed;
 392
 393   /* Is TIMEVAR currently running as a standalone timer?  */
 394   if (tv->standalone)
 395     /* Add the time elapsed since the it was started.  */
 396     timevar_add (elapsed, &tv->start_time);
 397
 398   /* Is TIMEVAR at the top of the timer stack?  */
 399   if (stack->timevar == tv)
 400     /* Add the elapsed time since it was pushed.  */
 401     timevar_add (elapsed, &start_time);
 402 }
 403
 404 /* Summarize timing variables to FP.  The timing variable TV_TOTAL has
 405    a special meaning -- it's considered to be the total elapsed time,
 406    for normalizing the others, and is displayed last.  */
 407
 408 void
 409 timevar_print (fp)
 410      FILE *fp;
 411 {
 412   /* Only print stuff if we have some sort of time information.  */
 413 #if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
 414   timevar_id_t id;
 415   struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
 416   struct timevar_time_def now;
 417
 418   if (!TIMEVAR_ENABLE)
 419     return;
 420
 421   /* Update timing information in case we're calling this from GDB.  */
 422
 423   if (fp == 0)
 424     fp = stderr;
 425
 426   /* What time is it?  */
 427   get_time (&now);
 428
 429   /* If the stack isn't empty, attribute the current elapsed time to
 430      the old topmost element.  */
 431   if (stack)
 432     timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
 433
 434   /* Reset the start time; from now on, time is attributed to
 435      TIMEVAR. */
 436   start_time = now;
 437
 438   fprintf (fp, _("\nExecution times (seconds)\n"));
 439   for (id = 0; id < TIMEVAR_LAST; ++id)
 440     {
 441       struct timevar_def *tv = &timevars[id];
 442
 443       /* Don't print the total execution time here; that goes at the
 444          end.  */
 445       if (id == TV_TOTAL)
 446         continue;
 447
 448       /* Don't print timing variables that were never used.  */
 449       if (!tv->used)
 450         continue;
 451
 452       /* The timing variable name.  */
 453       fprintf (fp, " %-22s:", tv->name);
 454
 455 #ifdef HAVE_USER_TIME
 456       /* Print user-mode time for this process.  */
 457       fprintf (fp, "%4ld.%02ld (%2.0f%%) usr",
 458                tv->elapsed.user / 1000000,
 459                (tv->elapsed.user % 1000000) / 10000,
 460                (total->user == 0) ? 0.0
 461                : (100.0 * tv->elapsed.user / (double) total->user));
 462 #endif /* HAVE_USER_TIME */
 463
 464 #ifdef HAVE_SYS_TIME
 465       /* Print system-mode time for this process.  */
 466       fprintf (fp, "%4ld.%02ld (%2.0f%%) sys",
 467                tv->elapsed.sys / 1000000,
 468                (tv->elapsed.sys % 1000000) / 10000,
 469                (total->sys == 0) ? 0.0
 470                : (100.0 * tv->elapsed.sys / (double) total->sys));
 471 #endif /* HAVE_SYS_TIME */
 472
 473 #ifdef HAVE_WALL_TIME
 474       /* Print wall clock time elapsed.  */
 475       fprintf (fp, "%4ld.%02ld (%2.0f%%) wall",
 476                tv->elapsed.wall / 1000000,
 477                (tv->elapsed.wall % 1000000) / 10000,
 478                (total->wall == 0) ? 0.0
 479                : (100.0 * tv->elapsed.wall / (double) total->wall));
 480 #endif /* HAVE_WALL_TIME */
 481
 482       fprintf (fp, "\n");
 483     }
 484
 485   /* Print total time.  */
 486   fprintf (fp, _(" TOTAL                 :"));
 487 #ifdef HAVE_USER_TIME
 488   fprintf (fp, "%4ld.%02ld          ",
 489            total->user / 1000000, (total->user % 1000000) / 10000);
 490 #endif
 491 #ifdef HAVE_SYS_TIME
 492   fprintf (fp, "%4ld.%02ld          ",
 493            total->sys  / 1000000, (total->sys  % 1000000) / 10000);
 494 #endif
 495 #ifdef HAVE_WALL_TIME
 496   fprintf (fp, "%4ld.%02ld\n",
 497            total->wall / 1000000, (total->wall % 1000000) / 10000);
 498 #endif
 499
 500 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
 501           || defined (HAVE_WALL_TIME) */
 502 }
 503
 504 /* Returns time (user + system) used so far by the compiler process,
 505    in microseconds.  */
 506
 507 long
 508 get_run_time ()
 509 {
 510   struct timevar_time_def total_elapsed;
 511   timevar_get (TV_TOTAL, &total_elapsed);
 512   return total_elapsed.user + total_elapsed.sys;
 513 }
 514
 515 /* Prints a message to stderr stating that time elapsed in STR is
 516    TOTAL (given in microseconds).  */
 517
 518 void
 519 print_time (str, total)
 520      const char *str;
 521      long total;
 522 {
 523   long all_time = get_run_time ();
 524   fprintf (stderr,
 525            _("time in %s: %ld.%06ld (%ld%%)\n"),
 526            str, total / 1000000, total % 1000000,
 527            all_time == 0 ? 0
 528            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
 529 }