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