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