timevar.c revision 132718
1/* Timing variables for measuring compiler performance. 2 Copyright (C) 2000, 2003 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, 59 Temple Place - Suite 330, Boston, MA 2002111-1307, 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 116static bool timevar_enable; 117 118/* See timevar.h for an explanation of timing variables. */ 119 120/* A timing variable. */ 121 122struct timevar_def 123{ 124 /* Elapsed time for this variable. */ 125 struct timevar_time_def elapsed; 126 127 /* If this variable is timed independently of the timing stack, 128 using timevar_start, this contains the start time. */ 129 struct timevar_time_def start_time; 130 131 /* The name of this timing variable. */ 132 const char *name; 133 134 /* Nonzero if this timing variable is running as a standalone 135 timer. */ 136 unsigned standalone : 1; 137 138 /* Nonzero if this timing variable was ever started or pushed onto 139 the timing stack. */ 140 unsigned used : 1; 141}; 142 143/* An element on the timing stack. Elapsed time is attributed to the 144 topmost timing variable on the stack. */ 145 146struct timevar_stack_def 147{ 148 /* The timing variable at this stack level. */ 149 struct timevar_def *timevar; 150 151 /* The next lower timing variable context in the stack. */ 152 struct timevar_stack_def *next; 153}; 154 155/* Declared timing variables. Constructed from the contents of 156 timevar.def. */ 157static struct timevar_def timevars[TIMEVAR_LAST]; 158 159/* The top of the timing stack. */ 160static struct timevar_stack_def *stack; 161 162/* A list of unused (i.e. allocated and subsequently popped) 163 timevar_stack_def instances. */ 164static struct timevar_stack_def *unused_stack_instances; 165 166/* The time at which the topmost element on the timing stack was 167 pushed. Time elapsed since then is attributed to the topmost 168 element. */ 169static struct timevar_time_def start_time; 170 171static void get_time (struct timevar_time_def *); 172static void timevar_accumulate (struct timevar_time_def *, 173 struct timevar_time_def *, 174 struct timevar_time_def *); 175 176/* Fill the current times into TIME. The definition of this function 177 also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and 178 HAVE_WALL_TIME macros. */ 179 180static void 181get_time (struct timevar_time_def *now) 182{ 183 now->user = 0; 184 now->sys = 0; 185 now->wall = 0; 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 211static void 212timevar_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} 220 221/* Initialize timing variables. */ 222 223void 224timevar_init (void) 225{ 226 timevar_enable = true; 227 228 /* Zero all elapsed times. */ 229 memset (timevars, 0, sizeof (timevars)); 230 231 /* Initialize the names of timing variables. */ 232#define DEFTIMEVAR(identifier__, name__) \ 233 timevars[identifier__].name = name__; 234#include "timevar.def" 235#undef DEFTIMEVAR 236 237#ifdef USE_TIMES 238 ticks_to_msec = TICKS_TO_MSEC; 239#endif 240#ifdef USE_CLOCK 241 clocks_to_msec = CLOCKS_TO_MSEC; 242#endif 243} 244 245/* Push TIMEVAR onto the timing stack. No further elapsed time is 246 attributed to the previous topmost timing variable on the stack; 247 subsequent elapsed time is attributed to TIMEVAR, until it is 248 popped or another element is pushed on top. 249 250 TIMEVAR cannot be running as a standalone timer. */ 251 252void 253timevar_push (timevar_id_t timevar) 254{ 255 struct timevar_def *tv = &timevars[timevar]; 256 struct timevar_stack_def *context; 257 struct timevar_time_def now; 258 259 if (!timevar_enable) 260 return; 261 262 /* Mark this timing variable as used. */ 263 tv->used = 1; 264 265 /* Can't push a standalone timer. */ 266 if (tv->standalone) 267 abort (); 268 269 /* What time is it? */ 270 get_time (&now); 271 272 /* If the stack isn't empty, attribute the current elapsed time to 273 the old topmost element. */ 274 if (stack) 275 timevar_accumulate (&stack->timevar->elapsed, &start_time, &now); 276 277 /* Reset the start time; from now on, time is attributed to 278 TIMEVAR. */ 279 start_time = now; 280 281 /* See if we have a previously-allocated stack instance. If so, 282 take it off the list. If not, malloc a new one. */ 283 if (unused_stack_instances != NULL) 284 { 285 context = unused_stack_instances; 286 unused_stack_instances = unused_stack_instances->next; 287 } 288 else 289 context = xmalloc (sizeof (struct timevar_stack_def)); 290 291 /* Fill it in and put it on the stack. */ 292 context->timevar = tv; 293 context->next = stack; 294 stack = context; 295} 296 297/* Pop the topmost timing variable element off the timing stack. The 298 popped variable must be TIMEVAR. Elapsed time since the that 299 element was pushed on, or since it was last exposed on top of the 300 stack when the element above it was popped off, is credited to that 301 timing variable. */ 302 303void 304timevar_pop (timevar_id_t timevar) 305{ 306 struct timevar_time_def now; 307 struct timevar_stack_def *popped = stack; 308 309 if (!timevar_enable) 310 return; 311 312 if (&timevars[timevar] != stack->timevar) 313 { 314 sorry ("cannot timevar_pop '%s' when top of timevars stack is '%s'", 315 timevars[timevar].name, stack->timevar->name); 316 abort (); 317 } 318 319 /* What time is it? */ 320 get_time (&now); 321 322 /* Attribute the elapsed time to the element we're popping. */ 323 timevar_accumulate (&popped->timevar->elapsed, &start_time, &now); 324 325 /* Reset the start time; from now on, time is attributed to the 326 element just exposed on the stack. */ 327 start_time = now; 328 329 /* Take the item off the stack. */ 330 stack = stack->next; 331 332 /* Don't delete the stack element; instead, add it to the list of 333 unused elements for later use. */ 334 popped->next = unused_stack_instances; 335 unused_stack_instances = popped; 336} 337 338/* Start timing TIMEVAR independently of the timing stack. Elapsed 339 time until timevar_stop is called for the same timing variable is 340 attributed to TIMEVAR. */ 341 342void 343timevar_start (timevar_id_t timevar) 344{ 345 struct timevar_def *tv = &timevars[timevar]; 346 347 if (!timevar_enable) 348 return; 349 350 /* Mark this timing variable as used. */ 351 tv->used = 1; 352 353 /* Don't allow the same timing variable to be started more than 354 once. */ 355 if (tv->standalone) 356 abort (); 357 tv->standalone = 1; 358 359 get_time (&tv->start_time); 360} 361 362/* Stop timing TIMEVAR. Time elapsed since timevar_start was called 363 is attributed to it. */ 364 365void 366timevar_stop (timevar_id_t timevar) 367{ 368 struct timevar_def *tv = &timevars[timevar]; 369 struct timevar_time_def now; 370 371 if (!timevar_enable) 372 return; 373 374 /* TIMEVAR must have been started via timevar_start. */ 375 if (!tv->standalone) 376 abort (); 377 378 get_time (&now); 379 timevar_accumulate (&tv->elapsed, &tv->start_time, &now); 380} 381 382/* Fill the elapsed time for TIMEVAR into ELAPSED. Returns 383 update-to-date information even if TIMEVAR is currently running. */ 384 385void 386timevar_get (timevar_id_t timevar, struct timevar_time_def *elapsed) 387{ 388 struct timevar_def *tv = &timevars[timevar]; 389 struct timevar_time_def now; 390 391 *elapsed = tv->elapsed; 392 393 /* Is TIMEVAR currently running as a standalone timer? */ 394 if (tv->standalone) 395 { 396 get_time (&now); 397 timevar_accumulate (elapsed, &tv->start_time, &now); 398 } 399 /* Or is TIMEVAR at the top of the timer stack? */ 400 else if (stack->timevar == tv) 401 { 402 get_time (&now); 403 timevar_accumulate (elapsed, &start_time, &now); 404 } 405} 406 407/* Summarize timing variables to FP. The timing variable TV_TOTAL has 408 a special meaning -- it's considered to be the total elapsed time, 409 for normalizing the others, and is displayed last. */ 410 411void 412timevar_print (FILE *fp) 413{ 414 /* Only print stuff if we have some sort of time information. */ 415#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME) 416 unsigned int /* timevar_id_t */ id; 417 struct timevar_time_def *total = &timevars[TV_TOTAL].elapsed; 418 struct timevar_time_def now; 419 420 if (!timevar_enable) 421 return; 422 423 /* Update timing information in case we're calling this from GDB. */ 424 425 if (fp == 0) 426 fp = stderr; 427 428 /* What time is it? */ 429 get_time (&now); 430 431 /* If the stack isn't empty, attribute the current elapsed time to 432 the old topmost element. */ 433 if (stack) 434 timevar_accumulate (&stack->timevar->elapsed, &start_time, &now); 435 436 /* Reset the start time; from now on, time is attributed to 437 TIMEVAR. */ 438 start_time = now; 439 440 fputs (_("\nExecution times (seconds)\n"), fp); 441 for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id) 442 { 443 struct timevar_def *tv = &timevars[(timevar_id_t) id]; 444 const double tiny = 5e-3; 445 446 /* Don't print the total execution time here; that goes at the 447 end. */ 448 if ((timevar_id_t) id == TV_TOTAL) 449 continue; 450 451 /* Don't print timing variables that were never used. */ 452 if (!tv->used) 453 continue; 454 455 /* Don't print timing variables if we're going to get a row of 456 zeroes. */ 457 if (tv->elapsed.user < tiny 458 && tv->elapsed.sys < tiny 459 && tv->elapsed.wall < tiny) 460 continue; 461 462 /* The timing variable name. */ 463 fprintf (fp, " %-22s:", tv->name); 464 465#ifdef HAVE_USER_TIME 466 /* Print user-mode time for this process. */ 467 fprintf (fp, "%7.2f (%2.0f%%) usr", 468 tv->elapsed.user, 469 (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100); 470#endif /* HAVE_USER_TIME */ 471 472#ifdef HAVE_SYS_TIME 473 /* Print system-mode time for this process. */ 474 fprintf (fp, "%7.2f (%2.0f%%) sys", 475 tv->elapsed.sys, 476 (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100); 477#endif /* HAVE_SYS_TIME */ 478 479#ifdef HAVE_WALL_TIME 480 /* Print wall clock time elapsed. */ 481 fprintf (fp, "%7.2f (%2.0f%%) wall", 482 tv->elapsed.wall, 483 (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100); 484#endif /* HAVE_WALL_TIME */ 485 486 putc ('\n', fp); 487 } 488 489 /* Print total time. */ 490 fputs (_(" TOTAL :"), fp); 491#ifdef HAVE_USER_TIME 492 fprintf (fp, "%7.2f ", total->user); 493#endif 494#ifdef HAVE_SYS_TIME 495 fprintf (fp, "%7.2f ", total->sys); 496#endif 497#ifdef HAVE_WALL_TIME 498 fprintf (fp, "%7.2f\n", total->wall); 499#endif 500 501#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) 502 || defined (HAVE_WALL_TIME) */ 503} 504 505/* Prints a message to stderr stating that time elapsed in STR is 506 TOTAL (given in microseconds). */ 507 508void 509print_time (const char *str, long total) 510{ 511 long all_time = get_run_time (); 512 fprintf (stderr, 513 _("time in %s: %ld.%06ld (%ld%%)\n"), 514 str, total / 1000000, total % 1000000, 515 all_time == 0 ? 0 516 : (long) (((100.0 * (double) total) / (double) all_time) + .5)); 517} 518