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