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