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 5This file is part of GCC. 6 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 9Software Foundation; either version 2, or (at your option) any later 10version. 11 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. 16 17You should have received a copy of the GNU General Public License 18along with GCC; see the file COPYING. If not, write to the Free 19Software Foundation, 51 Franklin Street, Fifth Floor, Boston, MA 2002110-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 37typedef int clock_t; 38#endif 39 40#ifndef HAVE_STRUCT_TMS 41struct 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 104static double ticks_to_msec; 105#define TICKS_TO_MSEC (1 / (double)TICKS_PER_SECOND) 106#endif 107 108#ifdef USE_CLOCK 109static 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 116bool timevar_enable; 117 118/* Total amount of memory allocated by garbage collector. */ 119 120size_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 131struct 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 155struct 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. */ 166static struct timevar_def timevars[TIMEVAR_LAST]; 167 168/* The top of the timing stack. */ 169static struct timevar_stack_def *stack; 170 171/* A list of unused (i.e. allocated and subsequently popped) 172 timevar_stack_def instances. */ 173static 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. */ 178static struct timevar_time_def start_time; 179 180static void get_time (struct timevar_time_def *); 181static 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 189static void 190get_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 221static void 222timevar_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 234void 235timevar_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 263void 264timevar_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 310void 311timevar_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 341void 342timevar_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 363void 364timevar_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 383void 384timevar_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 494void 495print_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