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