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