1/* Timing variables for measuring compiler performance.
2   Copyright (C) 2000, 2003, 2004, 2005, 2007 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 3, 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 COPYING3.  If not see
19<http://www.gnu.org/licenses/>.  */
20
21#include "config.h"
22#include "system.h"
23#ifdef HAVE_SYS_TIMES_H
24# include <sys/times.h>
25#endif
26#ifdef HAVE_SYS_RESOURCE_H
27#include <sys/resource.h>
28#endif
29#include "coretypes.h"
30#include "tm.h"
31#include "intl.h"
32#include "rtl.h"
33#include "toplev.h"
34
35#ifndef HAVE_CLOCK_T
36typedef int clock_t;
37#endif
38
39#ifndef HAVE_STRUCT_TMS
40struct tms
41{
42  clock_t tms_utime;
43  clock_t tms_stime;
44  clock_t tms_cutime;
45  clock_t tms_cstime;
46};
47#endif
48
49#ifndef RUSAGE_SELF
50# define RUSAGE_SELF 0
51#endif
52
53/* Calculation of scale factor to convert ticks to microseconds.
54   We mustn't use CLOCKS_PER_SEC except with clock().  */
55#if HAVE_SYSCONF && defined _SC_CLK_TCK
56# define TICKS_PER_SECOND sysconf (_SC_CLK_TCK) /* POSIX 1003.1-1996 */
57#else
58# ifdef CLK_TCK
59#  define TICKS_PER_SECOND CLK_TCK /* POSIX 1003.1-1988; obsolescent */
60# else
61#  ifdef HZ
62#   define TICKS_PER_SECOND HZ  /* traditional UNIX */
63#  else
64#   define TICKS_PER_SECOND 100 /* often the correct value */
65#  endif
66# endif
67#endif
68
69/* Prefer times to getrusage to clock (each gives successively less
70   information).  */
71#ifdef HAVE_TIMES
72# if defined HAVE_DECL_TIMES && !HAVE_DECL_TIMES
73  extern clock_t times (struct tms *);
74# endif
75# define USE_TIMES
76# define HAVE_USER_TIME
77# define HAVE_SYS_TIME
78# define HAVE_WALL_TIME
79#else
80#ifdef HAVE_GETRUSAGE
81# if defined HAVE_DECL_GETRUSAGE && !HAVE_DECL_GETRUSAGE
82  extern int getrusage (int, struct rusage *);
83# endif
84# define USE_GETRUSAGE
85# define HAVE_USER_TIME
86# define HAVE_SYS_TIME
87#else
88#ifdef HAVE_CLOCK
89# if defined HAVE_DECL_CLOCK && !HAVE_DECL_CLOCK
90  extern clock_t clock (void);
91# endif
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 double ticks_to_msec;
104#define TICKS_TO_MSEC (1 / (double)TICKS_PER_SECOND)
105#endif
106
107#ifdef USE_CLOCK
108static double clocks_to_msec;
109#define CLOCKS_TO_MSEC (1 / (double)CLOCKS_PER_SEC)
110#endif
111
112#include "flags.h"
113#include "timevar.h"
114
115bool timevar_enable;
116
117/* Total amount of memory allocated by garbage collector.  */
118
119size_t timevar_ggc_mem_total;
120
121/* The amount of memory that will cause us to report the timevar even
122   if the time spent is not significant.  */
123
124#define GGC_MEM_BOUND (1 << 20)
125
126/* See timevar.h for an explanation of timing variables.  */
127
128/* A timing variable.  */
129
130struct timevar_def
131{
132  /* Elapsed time for this variable.  */
133  struct timevar_time_def elapsed;
134
135  /* If this variable is timed independently of the timing stack,
136     using timevar_start, this contains the start time.  */
137  struct timevar_time_def start_time;
138
139  /* The name of this timing variable.  */
140  const char *name;
141
142  /* Nonzero if this timing variable is running as a standalone
143     timer.  */
144  unsigned standalone : 1;
145
146  /* Nonzero if this timing variable was ever started or pushed onto
147     the timing stack.  */
148  unsigned used : 1;
149};
150
151/* An element on the timing stack.  Elapsed time is attributed to the
152   topmost timing variable on the stack.  */
153
154struct timevar_stack_def
155{
156  /* The timing variable at this stack level.  */
157  struct timevar_def *timevar;
158
159  /* The next lower timing variable context in the stack.  */
160  struct timevar_stack_def *next;
161};
162
163/* Declared timing variables.  Constructed from the contents of
164   timevar.def.  */
165static struct timevar_def timevars[TIMEVAR_LAST];
166
167/* The top of the timing stack.  */
168static struct timevar_stack_def *stack;
169
170/* A list of unused (i.e. allocated and subsequently popped)
171   timevar_stack_def instances.  */
172static struct timevar_stack_def *unused_stack_instances;
173
174/* The time at which the topmost element on the timing stack was
175   pushed.  Time elapsed since then is attributed to the topmost
176   element.  */
177static struct timevar_time_def start_time;
178
179static void get_time (struct timevar_time_def *);
180static void timevar_accumulate (struct timevar_time_def *,
181				struct timevar_time_def *,
182				struct timevar_time_def *);
183
184/* Fill the current times into TIME.  The definition of this function
185   also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and
186   HAVE_WALL_TIME macros.  */
187
188static void
189get_time (struct timevar_time_def *now)
190{
191  now->user = 0;
192  now->sys  = 0;
193  now->wall = 0;
194  now->ggc_mem = timevar_ggc_mem_total;
195
196  if (!timevar_enable)
197    return;
198
199  {
200#ifdef USE_TIMES
201    struct tms tms;
202    now->wall = times (&tms)  * ticks_to_msec;
203    now->user = tms.tms_utime * ticks_to_msec;
204    now->sys  = tms.tms_stime * ticks_to_msec;
205#endif
206#ifdef USE_GETRUSAGE
207    struct rusage rusage;
208    getrusage (RUSAGE_SELF, &rusage);
209    now->user = rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
210    now->sys  = rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
211#endif
212#ifdef USE_CLOCK
213    now->user = clock () * clocks_to_msec;
214#endif
215  }
216}
217
218/* Add the difference between STOP_TIME and START_TIME to TIMER.  */
219
220static void
221timevar_accumulate (struct timevar_time_def *timer,
222		    struct timevar_time_def *start_time,
223		    struct timevar_time_def *stop_time)
224{
225  timer->user += stop_time->user - start_time->user;
226  timer->sys += stop_time->sys - start_time->sys;
227  timer->wall += stop_time->wall - start_time->wall;
228  timer->ggc_mem += stop_time->ggc_mem - start_time->ggc_mem;
229}
230
231/* Initialize timing variables.  */
232
233void
234timevar_init (void)
235{
236  timevar_enable = true;
237
238  /* Zero all elapsed times.  */
239  memset (timevars, 0, sizeof (timevars));
240
241  /* Initialize the names of timing variables.  */
242#define DEFTIMEVAR(identifier__, name__) \
243  timevars[identifier__].name = name__;
244#include "timevar.def"
245#undef DEFTIMEVAR
246
247#ifdef USE_TIMES
248  ticks_to_msec = TICKS_TO_MSEC;
249#endif
250#ifdef USE_CLOCK
251  clocks_to_msec = CLOCKS_TO_MSEC;
252#endif
253}
254
255/* Push TIMEVAR onto the timing stack.  No further elapsed time is
256   attributed to the previous topmost timing variable on the stack;
257   subsequent elapsed time is attributed to TIMEVAR, until it is
258   popped or another element is pushed on top.
259
260   TIMEVAR cannot be running as a standalone timer.  */
261
262void
263timevar_push_1 (timevar_id_t timevar)
264{
265  struct timevar_def *tv = &timevars[timevar];
266  struct timevar_stack_def *context;
267  struct timevar_time_def now;
268
269  /* Mark this timing variable as used.  */
270  tv->used = 1;
271
272  /* Can't push a standalone timer.  */
273  gcc_assert (!tv->standalone);
274
275  /* What time is it?  */
276  get_time (&now);
277
278  /* If the stack isn't empty, attribute the current elapsed time to
279     the old topmost element.  */
280  if (stack)
281    timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
282
283  /* Reset the start time; from now on, time is attributed to
284     TIMEVAR.  */
285  start_time = now;
286
287  /* See if we have a previously-allocated stack instance.  If so,
288     take it off the list.  If not, malloc a new one.  */
289  if (unused_stack_instances != NULL)
290    {
291      context = unused_stack_instances;
292      unused_stack_instances = unused_stack_instances->next;
293    }
294  else
295    context = XNEW (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_1 (timevar_id_t timevar)
311{
312  struct timevar_time_def now;
313  struct timevar_stack_def *popped = stack;
314
315  gcc_assert (&timevars[timevar] == stack->timevar);
316
317  /* What time is it?  */
318  get_time (&now);
319
320  /* Attribute the elapsed time to the element we're popping.  */
321  timevar_accumulate (&popped->timevar->elapsed, &start_time, &now);
322
323  /* Reset the start time; from now on, time is attributed to the
324     element just exposed on the stack.  */
325  start_time = now;
326
327  /* Take the item off the stack.  */
328  stack = stack->next;
329
330  /* Don't delete the stack element; instead, add it to the list of
331     unused elements for later use.  */
332  popped->next = unused_stack_instances;
333  unused_stack_instances = popped;
334}
335
336/* Start timing TIMEVAR independently of the timing stack.  Elapsed
337   time until timevar_stop is called for the same timing variable is
338   attributed to TIMEVAR.  */
339
340void
341timevar_start (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  gcc_assert (!tv->standalone);
354  tv->standalone = 1;
355
356  get_time (&tv->start_time);
357}
358
359/* Stop timing TIMEVAR.  Time elapsed since timevar_start was called
360   is attributed to it.  */
361
362void
363timevar_stop (timevar_id_t timevar)
364{
365  struct timevar_def *tv = &timevars[timevar];
366  struct timevar_time_def now;
367
368  if (!timevar_enable)
369    return;
370
371  /* TIMEVAR must have been started via timevar_start.  */
372  gcc_assert (tv->standalone);
373
374  get_time (&now);
375  timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
376}
377
378/* Summarize timing variables to FP.  The timing variable TV_TOTAL has
379   a special meaning -- it's considered to be the total elapsed time,
380   for normalizing the others, and is displayed last.  */
381
382void
383timevar_print (FILE *fp)
384{
385  /* Only print stuff if we have some sort of time information.  */
386#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME)
387  unsigned int /* timevar_id_t */ id;
388  struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
389  struct timevar_time_def now;
390
391  if (!timevar_enable)
392    return;
393
394  /* Update timing information in case we're calling this from GDB.  */
395
396  if (fp == 0)
397    fp = stderr;
398
399  /* What time is it?  */
400  get_time (&now);
401
402  /* If the stack isn't empty, attribute the current elapsed time to
403     the old topmost element.  */
404  if (stack)
405    timevar_accumulate (&stack->timevar->elapsed, &start_time, &now);
406
407  /* Reset the start time; from now on, time is attributed to
408     TIMEVAR.  */
409  start_time = now;
410
411  fputs (_("\nExecution times (seconds)\n"), fp);
412  for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
413    {
414      struct timevar_def *tv = &timevars[(timevar_id_t) id];
415      const double tiny = 5e-3;
416
417      /* Don't print the total execution time here; that goes at the
418	 end.  */
419      if ((timevar_id_t) id == TV_TOTAL)
420	continue;
421
422      /* Don't print timing variables that were never used.  */
423      if (!tv->used)
424	continue;
425
426      /* Don't print timing variables if we're going to get a row of
427         zeroes.  */
428      if (tv->elapsed.user < tiny
429	  && tv->elapsed.sys < tiny
430	  && tv->elapsed.wall < tiny
431	  && tv->elapsed.ggc_mem < GGC_MEM_BOUND)
432	continue;
433
434      /* The timing variable name.  */
435      fprintf (fp, " %-22s:", tv->name);
436
437#ifdef HAVE_USER_TIME
438      /* Print user-mode time for this process.  */
439      fprintf (fp, "%7.2f (%2.0f%%) usr",
440	       tv->elapsed.user,
441	       (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
442#endif /* HAVE_USER_TIME */
443
444#ifdef HAVE_SYS_TIME
445      /* Print system-mode time for this process.  */
446      fprintf (fp, "%7.2f (%2.0f%%) sys",
447	       tv->elapsed.sys,
448	       (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
449#endif /* HAVE_SYS_TIME */
450
451#ifdef HAVE_WALL_TIME
452      /* Print wall clock time elapsed.  */
453      fprintf (fp, "%7.2f (%2.0f%%) wall",
454	       tv->elapsed.wall,
455	       (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
456#endif /* HAVE_WALL_TIME */
457
458      /* Print the amount of ggc memory allocated.  */
459      fprintf (fp, "%8u kB (%2.0f%%) ggc",
460	       (unsigned) (tv->elapsed.ggc_mem >> 10),
461	       (total->ggc_mem == 0
462		? 0
463		: (float) tv->elapsed.ggc_mem / total->ggc_mem) * 100);
464
465      putc ('\n', fp);
466    }
467
468  /* Print total time.  */
469  fputs (_(" TOTAL                 :"), fp);
470#ifdef HAVE_USER_TIME
471  fprintf (fp, "%7.2f          ", total->user);
472#endif
473#ifdef HAVE_SYS_TIME
474  fprintf (fp, "%7.2f          ", total->sys);
475#endif
476#ifdef HAVE_WALL_TIME
477  fprintf (fp, "%7.2f           ", total->wall);
478#endif
479  fprintf (fp, "%8u kB\n", (unsigned) (total->ggc_mem >> 10));
480
481#ifdef ENABLE_CHECKING
482  fprintf (fp, "Extra diagnostic checks enabled; compiler may run slowly.\n");
483  fprintf (fp, "Configure with --enable-checking=release to disable checks.\n");
484#endif
485#ifndef ENABLE_ASSERT_CHECKING
486  fprintf (fp, "Internal checks disabled; compiler is not suited for release.\n");
487  fprintf (fp, "Configure with --enable-checking=release to enable checks.\n");
488#endif
489
490#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
491	  || defined (HAVE_WALL_TIME) */
492}
493
494/* Prints a message to stderr stating that time elapsed in STR is
495   TOTAL (given in microseconds).  */
496
497void
498print_time (const char *str, long total)
499{
500  long all_time = get_run_time ();
501  fprintf (stderr,
502	   _("time in %s: %ld.%06ld (%ld%%)\n"),
503	   str, total / 1000000, total % 1000000,
504	   all_time == 0 ? 0
505	   : (long) (((100.0 * (double) total) / (double) all_time) + .5));
506}
507