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
5 This file is part of GCC.
6
7 GCC is free software; you can redistribute it and/or modify it under
8 the terms of the GNU General Public License as published by the Free
9 Software Foundation; either version 2, or (at your option) any later
10 version.
11
12 GCC is distributed in the hope that it will be useful, but WITHOUT ANY
13 WARRANTY; without even the implied warranty of MERCHANTABILITY or
14 FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
15 for more details.
16
17 You should have received a copy of the GNU General Public License
18 along with GCC; see the file COPYING. If not, write to the Free
19 Software Foundation, 51 Franklin Street, Fifth Floor, Boston, MA
20 02110-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
37 typedef int clock_t;
38 #endif
39
40 #ifndef HAVE_STRUCT_TMS
41 struct 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
104 static double ticks_to_msec;
105 #define TICKS_TO_MSEC (1 / (double)TICKS_PER_SECOND)
106 #endif
107
108 #ifdef USE_CLOCK
109 static 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
116 bool timevar_enable;
117
118 /* Total amount of memory allocated by garbage collector. */
119
120 size_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
131 struct 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
155 struct 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. */
166 static struct timevar_def timevars[TIMEVAR_LAST];
167
168 /* The top of the timing stack. */
169 static struct timevar_stack_def *stack;
170
171 /* A list of unused (i.e. allocated and subsequently popped)
172 timevar_stack_def instances. */
173 static 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. */
178 static struct timevar_time_def start_time;
179
180 static void get_time (struct timevar_time_def *);
181 static 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
189 static void
get_time(struct timevar_time_def * now)190 get_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
221 static void
timevar_accumulate(struct timevar_time_def * timer,struct timevar_time_def * start_time,struct timevar_time_def * stop_time)222 timevar_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
234 void
timevar_init(void)235 timevar_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
263 void
timevar_push_1(timevar_id_t timevar)264 timevar_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
310 void
timevar_pop_1(timevar_id_t timevar)311 timevar_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
341 void
timevar_start(timevar_id_t timevar)342 timevar_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
363 void
timevar_stop(timevar_id_t timevar)364 timevar_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
383 void
timevar_print(FILE * fp)384 timevar_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
494 void
print_time(const char * str,long total)495 print_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