1/* Timing variables for measuring compiler performance.
2   Copyright (C) 2000, 2003, 2004, 2005 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, 51 Franklin Street, Fifth Floor, Boston, MA
2002110-1301, 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
116bool timevar_enable;
117
118/* Total amount of memory allocated by garbage collector.  */
119
120size_t timevar_ggc_mem_total;
121
122/* The amount of memory that will cause us to report the timevar even
123   if the time spent is not significant.  */
124
125#define GGC_MEM_BOUND (1 << 20)
126
127/* See timevar.h for an explanation of timing variables.  */
128
129/* A timing variable.  */
130
131struct timevar_def
132{
133  /* Elapsed time for this variable.  */
134  struct timevar_time_def elapsed;
135
136  /* If this variable is timed independently of the timing stack,
137     using timevar_start, this contains the start time.  */
138  struct timevar_time_def start_time;
139
140  /* The name of this timing variable.  */
141  const char *name;
142
143  /* Nonzero if this timing variable is running as a standalone
144     timer.  */
145  unsigned standalone : 1;
146
147  /* Nonzero if this timing variable was ever started or pushed onto
148     the timing stack.  */
149  unsigned used : 1;
150};
151
152/* An element on the timing stack.  Elapsed time is attributed to the
153   topmost timing variable on the stack.  */
154
155struct timevar_stack_def
156{
157  /* The timing variable at this stack level.  */
158  struct timevar_def *timevar;
159
160  /* The next lower timing variable context in the stack.  */
161  struct timevar_stack_def *next;
162};
163
164/* Declared timing variables.  Constructed from the contents of
165   timevar.def.  */
166static struct timevar_def timevars[TIMEVAR_LAST];
167
168/* The top of the timing stack.  */
169static struct timevar_stack_def *stack;
170
171/* A list of unused (i.e. allocated and subsequently popped)
172   timevar_stack_def instances.  */
173static struct timevar_stack_def *unused_stack_instances;
174
175/* The time at which the topmost element on the timing stack was
176   pushed.  Time elapsed since then is attributed to the topmost
177   element.  */
178static struct timevar_time_def start_time;
179
180static void get_time (struct timevar_time_def *);
181static void timevar_accumulate (struct timevar_time_def *,
182				struct timevar_time_def *,
183				struct timevar_time_def *);
184
185/* Fill the current times into TIME.  The definition of this function
186   also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
187   HAVE_WALL_TIME macros.  */
188
189static void
190get_time (struct timevar_time_def *now)
191{
192  now->user = 0;
193  now->sys  = 0;
194  now->wall = 0;
195  now->ggc_mem = timevar_ggc_mem_total;
196
197  if (!timevar_enable)
198    return;
199
200  {
201#ifdef USE_TIMES
202    struct tms tms;
203    now->wall = times (&tms)  * ticks_to_msec;
204    now->user = tms.tms_utime * ticks_to_msec;
205    now->sys  = tms.tms_stime * ticks_to_msec;
206#endif
207#ifdef USE_GETRUSAGE
208    struct rusage rusage;
209    getrusage (RUSAGE_SELF, &rusage);
210    now->user = rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
211    now->sys  = rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
212#endif
213#ifdef USE_CLOCK
214    now->user = clock () * clocks_to_msec;
215#endif
216  }
217}
218
219/* Add the difference between STOP_TIME and START_TIME to TIMER.  */
220
221static void
222timevar_accumulate (struct timevar_time_def *timer,
223		    struct timevar_time_def *start_time,
224		    struct timevar_time_def *stop_time)
225{
226  timer->user += stop_time->user - start_time->user;
227  timer->sys += stop_time->sys - start_time->sys;
228  timer->wall += stop_time->wall - start_time->wall;
229  timer->ggc_mem += stop_time->ggc_mem - start_time->ggc_mem;
230}
231
232/* Initialize timing variables.  */
233
234void
235timevar_init (void)
236{
237  timevar_enable = true;
238
239  /* Zero all elapsed times.  */
240  memset (timevars, 0, sizeof (timevars));
241
242  /* Initialize the names of timing variables.  */
243#define DEFTIMEVAR(identifier__, name__) \
244  timevars[identifier__].name = name__;
245#include "timevar.def"
246#undef DEFTIMEVAR
247
248#ifdef USE_TIMES
249  ticks_to_msec = TICKS_TO_MSEC;
250#endif
251#ifdef USE_CLOCK
252  clocks_to_msec = CLOCKS_TO_MSEC;
253#endif
254}
255
256/* Push TIMEVAR onto the timing stack.  No further elapsed time is
257   attributed to the previous topmost timing variable on the stack;
258   subsequent elapsed time is attributed to TIMEVAR, until it is
259   popped or another element is pushed on top.
260
261   TIMEVAR cannot be running as a standalone timer.  */
262
263void
264timevar_push_1 (timevar_id_t timevar)
265{
266  struct timevar_def *tv = &timevars[timevar];
267  struct timevar_stack_def *context;
268  struct timevar_time_def now;
269
270  /* Mark this timing variable as used.  */
271  tv->used = 1;
272
273  /* Can't push a standalone timer.  */
274  gcc_assert (!tv->standalone);
275
276  /* What time is it?  */
277  get_time (&now);
278
279  /* If the stack isn't empty, attribute the current elapsed time to
280     the old topmost element.  */
281  if (stack)
282    timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
283
284  /* Reset the start time; from now on, time is attributed to
285     TIMEVAR.  */
286  start_time = now;
287
288  /* See if we have a previously-allocated stack instance.  If so,
289     take it off the list.  If not, malloc a new one.  */
290  if (unused_stack_instances != NULL)
291    {
292      context = unused_stack_instances;
293      unused_stack_instances = unused_stack_instances->next;
294    }
295  else
296    context = XNEW (struct timevar_stack_def);
297
298  /* Fill it in and put it on the stack.  */
299  context->timevar = tv;
300  context->next = stack;
301  stack = context;
302}
303
304/* Pop the topmost timing variable element off the timing stack.  The
305   popped variable must be TIMEVAR.  Elapsed time since the that
306   element was pushed on, or since it was last exposed on top of the
307   stack when the element above it was popped off, is credited to that
308   timing variable.  */
309
310void
311timevar_pop_1 (timevar_id_t timevar)
312{
313  struct timevar_time_def now;
314  struct timevar_stack_def *popped = stack;
315
316  gcc_assert (&timevars[timevar] == stack->timevar);
317
318  /* What time is it?  */
319  get_time (&now);
320
321  /* Attribute the elapsed time to the element we're popping.  */
322  timevar_accumulate (&popped->timevar->elapsed, &start_time, &now);
323
324  /* Reset the start time; from now on, time is attributed to the
325     element just exposed on the stack.  */
326  start_time = now;
327
328  /* Take the item off the stack.  */
329  stack = stack->next;
330
331  /* Don't delete the stack element; instead, add it to the list of
332     unused elements for later use.  */
333  popped->next = unused_stack_instances;
334  unused_stack_instances = popped;
335}
336
337/* Start timing TIMEVAR independently of the timing stack.  Elapsed
338   time until timevar_stop is called for the same timing variable is
339   attributed to TIMEVAR.  */
340
341void
342timevar_start (timevar_id_t timevar)
343{
344  struct timevar_def *tv = &timevars[timevar];
345
346  if (!timevar_enable)
347    return;
348
349  /* Mark this timing variable as used.  */
350  tv->used = 1;
351
352  /* Don't allow the same timing variable to be started more than
353     once.  */
354  gcc_assert (!tv->standalone);
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
363void
364timevar_stop (timevar_id_t timevar)
365{
366  struct timevar_def *tv = &timevars[timevar];
367  struct timevar_time_def now;
368
369  if (!timevar_enable)
370    return;
371
372  /* TIMEVAR must have been started via timevar_start.  */
373  gcc_assert (tv->standalone);
374
375  get_time (&now);
376  timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
377}
378
379/* Summarize timing variables to FP.  The timing variable TV_TOTAL has
380   a special meaning -- it's considered to be the total elapsed time,
381   for normalizing the others, and is displayed last.  */
382
383void
384timevar_print (FILE *fp)
385{
386  /* Only print stuff if we have some sort of time information.  */
387#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
388  unsigned int /* timevar_id_t */ id;
389  struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
390  struct timevar_time_def now;
391
392  if (!timevar_enable)
393    return;
394
395  /* Update timing information in case we're calling this from GDB.  */
396
397  if (fp == 0)
398    fp = stderr;
399
400  /* What time is it?  */
401  get_time (&now);
402
403  /* If the stack isn't empty, attribute the current elapsed time to
404     the old topmost element.  */
405  if (stack)
406    timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
407
408  /* Reset the start time; from now on, time is attributed to
409     TIMEVAR.  */
410  start_time = now;
411
412  fputs (_("\nExecution times (seconds)\n"), fp);
413  for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
414    {
415      struct timevar_def *tv = &timevars[(timevar_id_t) id];
416      const double tiny = 5e-3;
417
418      /* Don't print the total execution time here; that goes at the
419	 end.  */
420      if ((timevar_id_t) id == TV_TOTAL)
421	continue;
422
423      /* Don't print timing variables that were never used.  */
424      if (!tv->used)
425	continue;
426
427      /* Don't print timing variables if we're going to get a row of
428         zeroes.  */
429      if (tv->elapsed.user < tiny
430	  && tv->elapsed.sys < tiny
431	  && tv->elapsed.wall < tiny
432	  && tv->elapsed.ggc_mem < GGC_MEM_BOUND)
433	continue;
434
435      /* The timing variable name.  */
436      fprintf (fp, " %-22s:", tv->name);
437
438#ifdef HAVE_USER_TIME
439      /* Print user-mode time for this process.  */
440      fprintf (fp, "%7.2f (%2.0f%%) usr",
441	       tv->elapsed.user,
442	       (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
443#endif /* HAVE_USER_TIME */
444
445#ifdef HAVE_SYS_TIME
446      /* Print system-mode time for this process.  */
447      fprintf (fp, "%7.2f (%2.0f%%) sys",
448	       tv->elapsed.sys,
449	       (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
450#endif /* HAVE_SYS_TIME */
451
452#ifdef HAVE_WALL_TIME
453      /* Print wall clock time elapsed.  */
454      fprintf (fp, "%7.2f (%2.0f%%) wall",
455	       tv->elapsed.wall,
456	       (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
457#endif /* HAVE_WALL_TIME */
458
459      /* Print the amount of ggc memory allocated.  */
460      fprintf (fp, "%8u kB (%2.0f%%) ggc",
461	       (unsigned) (tv->elapsed.ggc_mem >> 10),
462	       (total->ggc_mem == 0
463		? 0
464		: (float) tv->elapsed.ggc_mem / total->ggc_mem) * 100);
465
466      putc ('\n', fp);
467    }
468
469  /* Print total time.  */
470  fputs (_(" TOTAL                 :"), fp);
471#ifdef HAVE_USER_TIME
472  fprintf (fp, "%7.2f          ", total->user);
473#endif
474#ifdef HAVE_SYS_TIME
475  fprintf (fp, "%7.2f          ", total->sys);
476#endif
477#ifdef HAVE_WALL_TIME
478  fprintf (fp, "%7.2f           ", total->wall);
479#endif
480  fprintf (fp, "%8u kB\n", (unsigned) (total->ggc_mem >> 10));
481
482#ifdef ENABLE_CHECKING
483  fprintf (fp, "Extra diagnostic checks enabled; compiler may run slowly.\n");
484  fprintf (fp, "Configure with --disable-checking to disable checks.\n");
485#endif
486
487#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
488	  || defined (HAVE_WALL_TIME) */
489}
490
491/* Prints a message to stderr stating that time elapsed in STR is
492   TOTAL (given in microseconds).  */
493
494void
495print_time (const char *str, long total)
496{
497  long all_time = get_run_time ();
498  fprintf (stderr,
499	   _("time in %s: %ld.%06ld (%ld%%)\n"),
500	   str, total / 1000000, total % 1000000,
501	   all_time == 0 ? 0
502	   : (long) (((100.0 * (double) total) / (double) all_time) + .5));
503}
504