Merge branch 'vendor/GCC50' - gcc 5.0 snapshot 1 FEB 2015
[dragonfly.git] / contrib / gcc-5.0 / gcc / timevar.c
1 /* Timing variables for measuring compiler performance.
2    Copyright (C) 2000-2015 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 3, 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 COPYING3.  If not see
19 <http://www.gnu.org/licenses/>.  */
20
21 #include "config.h"
22 #include "system.h"
23 #include "timevar.h"
24
25 #ifndef HAVE_CLOCK_T
26 typedef int clock_t;
27 #endif
28
29 #ifndef HAVE_STRUCT_TMS
30 struct 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
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
59 /* Prefer times to getrusage to clock (each gives successively less
60    information).  */
61 #ifdef HAVE_TIMES
62 # if defined HAVE_DECL_TIMES && !HAVE_DECL_TIMES
63   extern clock_t times (struct tms *);
64 # endif
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
71 # if defined HAVE_DECL_GETRUSAGE && !HAVE_DECL_GETRUSAGE
72   extern int getrusage (int, struct rusage *);
73 # endif
74 # define USE_GETRUSAGE
75 # define HAVE_USER_TIME
76 # define HAVE_SYS_TIME
77 #else
78 #ifdef HAVE_CLOCK
79 # if defined HAVE_DECL_CLOCK && !HAVE_DECL_CLOCK
80   extern clock_t clock (void);
81 # endif
82 # define USE_CLOCK
83 # define HAVE_USER_TIME
84 #endif
85 #endif
86 #endif
87
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
93 static double ticks_to_msec;
94 #define TICKS_TO_MSEC (1 / (double)TICKS_PER_SECOND)
95 #endif
96
97 #ifdef USE_CLOCK
98 static double clocks_to_msec;
99 #define CLOCKS_TO_MSEC (1 / (double)CLOCKS_PER_SEC)
100 #endif
101
102 /* True if timevars should be used.  In GCC, this happens with
103    the -ftime-report flag.  */
104
105 bool timevar_enable;
106
107 /* Total amount of memory allocated by garbage collector.  */
108
109 size_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
116 /* See timevar.h for an explanation of timing variables.  */
117
118 /* A timing variable.  */
119
120 struct 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
129   /* The name of this timing variable.  */
130   const char *name;
131
132   /* Nonzero if this timing variable is running as a standalone
133      timer.  */
134   unsigned standalone : 1;
135
136   /* Nonzero if this timing variable was ever started or pushed onto
137      the timing stack.  */
138   unsigned used : 1;
139 };
140
141 /* An element on the timing stack.  Elapsed time is attributed to the
142    topmost timing variable on the stack.  */
143
144 struct 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.  */
155 static struct timevar_def timevars[TIMEVAR_LAST];
156
157 /* The top of the timing stack.  */
158 static struct timevar_stack_def *stack;
159
160 /* A list of unused (i.e. allocated and subsequently popped)
161    timevar_stack_def instances.  */
162 static struct timevar_stack_def *unused_stack_instances;
163
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.  */
167 static struct timevar_time_def start_time;
168
169 static void get_time (struct timevar_time_def *);
170 static void timevar_accumulate (struct timevar_time_def *,
171                                 struct timevar_time_def *,
172                                 struct timevar_time_def *);
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
176    HAVE_WALL_TIME macros.  */
177
178 static void
179 get_time (struct timevar_time_def *now)
180 {
181   now->user = 0;
182   now->sys  = 0;
183   now->wall = 0;
184   now->ggc_mem = timevar_ggc_mem_total;
185
186   if (!timevar_enable)
187     return;
188
189   {
190 #ifdef USE_TIMES
191     struct tms tms;
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;
195 #endif
196 #ifdef USE_GETRUSAGE
197     struct rusage rusage;
198     getrusage (RUSAGE_SELF, &rusage);
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;
201 #endif
202 #ifdef USE_CLOCK
203     now->user = clock () * clocks_to_msec;
204 #endif
205   }
206 }
207
208 /* Add the difference between STOP_TIME and START_TIME to TIMER.  */
209
210 static void
211 timevar_accumulate (struct timevar_time_def *timer,
212                     struct timevar_time_def *start_time,
213                     struct timevar_time_def *stop_time)
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;
218   timer->ggc_mem += stop_time->ggc_mem - start_time->ggc_mem;
219 }
220
221 /* Initialize timing variables.  */
222
223 void
224 timevar_init (void)
225 {
226   if (timevar_enable)
227     return;
228
229   timevar_enable = true;
230
231   /* Zero all elapsed times.  */
232   memset (timevars, 0, sizeof (timevars));
233
234   /* Initialize the names of timing variables.  */
235 #define DEFTIMEVAR(identifier__, name__) \
236   timevars[identifier__].name = name__;
237 #include "timevar.def"
238 #undef DEFTIMEVAR
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
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
251    popped or another element is pushed on top.
252
253    TIMEVAR cannot be running as a standalone timer.  */
254
255 void
256 timevar_push_1 (timevar_id_t timevar)
257 {
258   struct timevar_def *tv = &timevars[timevar];
259   struct timevar_stack_def *context;
260   struct timevar_time_def now;
261
262   /* Mark this timing variable as used.  */
263   tv->used = 1;
264
265   /* Can't push a standalone timer.  */
266   gcc_assert (!tv->standalone);
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
277      TIMEVAR.  */
278   start_time = now;
279
280   /* See if we have a previously-allocated stack instance.  If so,
281      take it off the list.  If not, malloc a new one.  */
282   if (unused_stack_instances != NULL)
283     {
284       context = unused_stack_instances;
285       unused_stack_instances = unused_stack_instances->next;
286     }
287   else
288     context = XNEW (struct timevar_stack_def);
289
290   /* Fill it in and put it on the stack.  */
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
302 void
303 timevar_pop_1 (timevar_id_t timevar)
304 {
305   struct timevar_time_def now;
306   struct timevar_stack_def *popped = stack;
307
308   gcc_assert (&timevars[timevar] == stack->timevar);
309
310   /* What time is it?  */
311   get_time (&now);
312
313   /* Attribute the elapsed time to the element we're popping.  */
314   timevar_accumulate (&popped->timevar->elapsed, &start_time, &now);
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
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;
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
333 void
334 timevar_start (timevar_id_t timevar)
335 {
336   struct timevar_def *tv = &timevars[timevar];
337
338   if (!timevar_enable)
339     return;
340
341   /* Mark this timing variable as used.  */
342   tv->used = 1;
343
344   /* Don't allow the same timing variable to be started more than
345      once.  */
346   gcc_assert (!tv->standalone);
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
355 void
356 timevar_stop (timevar_id_t timevar)
357 {
358   struct timevar_def *tv = &timevars[timevar];
359   struct timevar_time_def now;
360
361   if (!timevar_enable)
362     return;
363
364   /* TIMEVAR must have been started via timevar_start.  */
365   gcc_assert (tv->standalone);
366   tv->standalone = 0; /* Enable a restart.  */
367
368   get_time (&now);
369   timevar_accumulate (&tv->elapsed, &tv->start_time, &now);
370 }
371
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
379 bool
380 timevar_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
406 void
407 timevar_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
426 /* Validate that phase times are consistent.  */
427
428 static void
429 validate_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;
436   size_t phase_ggc_mem = 0;
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)
471         fprintf (fp, "ggc_mem %24lu > %24lu\n", (unsigned long)phase_ggc_mem,
472                  (unsigned long)total->ggc_mem);
473       gcc_unreachable ();
474     }
475 }
476
477
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
482 void
483 timevar_print (FILE *fp)
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)
487   unsigned int /* timevar_id_t */ id;
488   struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed;
489   struct timevar_time_def now;
490
491   if (!timevar_enable)
492     return;
493
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
508      TIMEVAR.  */
509   start_time = now;
510
511   fputs ("\nExecution times (seconds)\n", fp);
512   for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id)
513     {
514       struct timevar_def *tv = &timevars[(timevar_id_t) id];
515       const double tiny = 5e-3;
516
517       /* Don't print the total execution time here; that goes at the
518          end.  */
519       if ((timevar_id_t) id == TV_TOTAL)
520         continue;
521
522       /* Don't print timing variables that were never used.  */
523       if (!tv->used)
524         continue;
525
526       /* Don't print timing variables if we're going to get a row of
527          zeroes.  */
528       if (tv->elapsed.user < tiny
529           && tv->elapsed.sys < tiny
530           && tv->elapsed.wall < tiny
531           && tv->elapsed.ggc_mem < GGC_MEM_BOUND)
532         continue;
533
534       /* The timing variable name.  */
535       fprintf (fp, " %-24s:", tv->name);
536
537 #ifdef HAVE_USER_TIME
538       /* Print user-mode time for this process.  */
539       fprintf (fp, "%7.2f (%2.0f%%) usr",
540                tv->elapsed.user,
541                (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
542 #endif /* HAVE_USER_TIME */
543
544 #ifdef HAVE_SYS_TIME
545       /* Print system-mode time for this process.  */
546       fprintf (fp, "%7.2f (%2.0f%%) sys",
547                tv->elapsed.sys,
548                (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
549 #endif /* HAVE_SYS_TIME */
550
551 #ifdef HAVE_WALL_TIME
552       /* Print wall clock time elapsed.  */
553       fprintf (fp, "%7.2f (%2.0f%%) wall",
554                tv->elapsed.wall,
555                (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
556 #endif /* HAVE_WALL_TIME */
557
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
565       putc ('\n', fp);
566     }
567
568   /* Print total time.  */
569   fputs (" TOTAL                 :", fp);
570 #ifdef HAVE_USER_TIME
571   fprintf (fp, "%7.2f          ", total->user);
572 #endif
573 #ifdef HAVE_SYS_TIME
574   fprintf (fp, "%7.2f          ", total->sys);
575 #endif
576 #ifdef HAVE_WALL_TIME
577   fprintf (fp, "%7.2f           ", total->wall);
578 #endif
579   fprintf (fp, "%8u kB\n", (unsigned) (total->ggc_mem >> 10));
580
581 #ifdef ENABLE_CHECKING
582   fprintf (fp, "Extra diagnostic checks enabled; compiler may run slowly.\n");
583   fprintf (fp, "Configure with --enable-checking=release to disable checks.\n");
584 #endif
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");
588 #endif
589
590 #endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME)
591           || defined (HAVE_WALL_TIME) */
592
593   validate_phases (fp);
594 }
595
596 /* Prints a message to stderr stating that time elapsed in STR is
597    TOTAL (given in microseconds).  */
598
599 void
600 print_time (const char *str, long total)
601 {
602   long all_time = get_run_time ();
603   fprintf (stderr,
604            "time in %s: %ld.%06ld (%ld%%)\n",
605            str, total / 1000000, total % 1000000,
606            all_time == 0 ? 0
607            : (long) (((100.0 * (double) total) / (double) all_time) + .5));
608 }