From a2cd5d1f106f4dce3a93aede00cf082f144464be Mon Sep 17 00:00:00 2001 From: Andi Kleen Date: Wed, 2 Oct 2024 13:13:21 -0700 Subject: [PATCH] Remove sys/user time in -ftime-report Retrieving sys/user time in timevars is quite expensive because it always needs a system call. Only getting the wall time is much cheaper because operating systems have optimized paths for this. The sys time isn't that interesting for a compiler and wall time is usually close to user time except when the system is overloaded. On the other hand when it is not wall time is more accurate because it has less overhead. For building tramp3d with -O0 the -ftime-report overhead drops from 18% to 3%. For -O2 it drops from 8% to not measurable. I changed the code to use gettimeofday as a fallback for clock_gettime CLOCK_MONOTONIC. If a host has neither of those the time will not be measured. Previously clock was the fallback. This removes a lot of code in timevar.cc: gcc/timevar.cc | 167 ++++++--------------------------------------------------- gcc/timevar.h | 10 +--- 2 files changed, 17 insertions(+), 160 deletions(-) gcc/ChangeLog: * timevar.cc (struct tms): Remove. (RUSAGE_SELF): Remove. (TICKS_PER_SECOND): Remove. (USE_TIMES): Remove. (HAVE_USER_TIME): Remove. (HAVE_SYS_TIME): Remove. (HAVE_WALL_TIME): Remove. (USE_GETRUSAGE): Remove. (USE_CLOCK): Remove. (NANOSEC_PER_SEC): Remove. (TICKS_TO_NANOSEC): Remove. (CLOCKS_TO_NANOSEC): Remove. (timer::named_items::push): Remove sys/user. (get_time): Remove clock and times and getruage code. (timevar_accumulate): Remove sys/user. (timevar_diff): Dito. (timer::validate_phases): Dito. (timer::print_row): Dito. (timer::all_zero): Dito. (timer::print): Dito. (make_json_for_timevar_time_def): Dito. * timevar.h (struct timevar_time_def): Dito. --- gcc/timevar.cc | 189 ++++++------------------------------------------- gcc/timevar.h | 10 +-- 2 files changed, 22 insertions(+), 177 deletions(-) diff --git a/gcc/timevar.cc b/gcc/timevar.cc index 68bcf44864f..4a57e74230d 100644 --- a/gcc/timevar.cc +++ b/gcc/timevar.cc @@ -26,84 +26,6 @@ along with GCC; see the file COPYING3. If not see #include "options.h" #include "json.h" -#ifndef HAVE_CLOCK_T -typedef int clock_t; -#endif - -#ifndef HAVE_STRUCT_TMS -struct tms -{ - clock_t tms_utime; - clock_t tms_stime; - clock_t tms_cutime; - clock_t tms_cstime; -}; -#endif - -#ifndef RUSAGE_SELF -# define RUSAGE_SELF 0 -#endif - -/* Calculation of scale factor to convert ticks to seconds. - We mustn't use CLOCKS_PER_SEC except with clock(). */ -#if HAVE_SYSCONF && defined _SC_CLK_TCK -# define TICKS_PER_SECOND sysconf (_SC_CLK_TCK) /* POSIX 1003.1-1996 */ -#else -# ifdef CLK_TCK -# define TICKS_PER_SECOND CLK_TCK /* POSIX 1003.1-1988; obsolescent */ -# else -# ifdef HZ -# define TICKS_PER_SECOND HZ /* traditional UNIX */ -# else -# define TICKS_PER_SECOND 100 /* often the correct value */ -# endif -# endif -#endif - -/* Prefer times to getrusage to clock (each gives successively less - information). */ -#ifdef HAVE_TIMES -# if defined HAVE_DECL_TIMES && !HAVE_DECL_TIMES - extern clock_t times (struct tms *); -# endif -# define USE_TIMES -# define HAVE_USER_TIME -# define HAVE_SYS_TIME -# define HAVE_WALL_TIME -#else -#ifdef HAVE_GETRUSAGE -# if defined HAVE_DECL_GETRUSAGE && !HAVE_DECL_GETRUSAGE - extern int getrusage (int, struct rusage *); -# endif -# define USE_GETRUSAGE -# define HAVE_USER_TIME -# define HAVE_SYS_TIME -#else -#ifdef HAVE_CLOCK -# if defined HAVE_DECL_CLOCK && !HAVE_DECL_CLOCK - extern clock_t clock (void); -# endif -# define USE_CLOCK -# define HAVE_USER_TIME -#endif -#endif -#endif - -/* libc is very likely to have snuck a call to sysconf() into one of - the underlying constants, and that can be very slow, so we have to - precompute them. Whose wonderful idea was it to make all those - _constants_ variable at run time, anyway? */ -#define NANOSEC_PER_SEC 1000000000 -#ifdef USE_TIMES -static uint64_t ticks_to_nanosec; -#define TICKS_TO_NANOSEC (NANOSEC_PER_SEC / TICKS_PER_SECOND) -#endif - -#ifdef USE_CLOCK -static uint64_t clocks_to_nanosec; -#define CLOCKS_TO_NANOSEC (NANOSEC_PER_SEC / CLOCKS_PER_SEC) -#endif - /* Non-NULL if timevars should be used. In GCC, this happens with the -ftime-report flag. */ @@ -181,8 +103,6 @@ timer::named_items::push (const char *item_name) timer::timevar_def *def = &m_hash_map.get_or_insert (item_name, &existed); if (!existed) { - def->elapsed.user = 0; - def->elapsed.sys = 0; def->elapsed.wall = 0; def->name = item_name; def->standalone = 0; @@ -230,37 +150,27 @@ timer::named_items::make_json () const return arr; } -/* Fill the current times into TIME. The definition of this function - also defines any or all of the HAVE_USER_TIME, HAVE_SYS_TIME, and - HAVE_WALL_TIME macros. */ +/* Fill the current times into TIME, and define HAVE_WALL_TIME if there. */ static void get_time (struct timevar_time_def *now) { - now->user = 0; - now->sys = 0; now->wall = 0; now->ggc_mem = timevar_ggc_mem_total; - { -#ifdef USE_TIMES - struct tms tms; - now->wall = times (&tms) * ticks_to_nanosec; - now->user = tms.tms_utime * ticks_to_nanosec; - now->sys = tms.tms_stime * ticks_to_nanosec; +#if _POSIX_C_SOURCE >= 199309L + struct timespec ts; + clock_gettime (CLOCK_MONOTONIC, &ts); + now->wall = ts.tv_sec * 1000000000 + ts.tv_nsec; + return; +#define HAVE_WALL_TIME 1 #endif -#ifdef USE_GETRUSAGE - struct rusage rusage; - getrusage (RUSAGE_SELF, &rusage); - now->user = rusage.ru_utime.tv_sec * NANOSEC_PER_SEC - + rusage.ru_utime.tv_usec * 1000; - now->sys = rusage.ru_stime.tv_sec * NANOSEC_PER_SEC - + rusage.ru_stime.tv_usec * 1000; +#ifdef HAVE_GETTIMEOFDAY + struct timeval tv; + gettimeofday (&tv, NULL); + now->wall = tv.tv_sec * 1000000000 + tv.tv_usec * 1000; +#define HAVE_WALL_TIME 1 #endif -#ifdef USE_CLOCK - now->user = clock () * clocks_to_nanosec; -#endif - } } /* Add the difference between STOP_TIME and START_TIME to TIMER. */ @@ -270,8 +180,6 @@ timevar_accumulate (struct timevar_time_def *timer, struct timevar_time_def *start_time, struct timevar_time_def *stop_time) { - timer->user += stop_time->user - start_time->user; - timer->sys += stop_time->sys - start_time->sys; timer->wall += stop_time->wall - start_time->wall; timer->ggc_mem += stop_time->ggc_mem - start_time->ggc_mem; } @@ -283,8 +191,6 @@ timevar_diff (struct timevar_time_def *out, const timevar_time_def &start_time, const timevar_time_def &stop_time) { - out->user = stop_time.user - start_time.user; - out->sys = stop_time.sys - start_time.sys; out->wall = stop_time.wall - start_time.wall; out->ggc_mem = stop_time.ggc_mem - start_time.ggc_mem; } @@ -305,15 +211,6 @@ timer::timer () : m_timevars[identifier__].name = name__; #include "timevar.def" #undef DEFTIMEVAR - - /* Initialize configuration-specific state. - Ideally this would be one-time initialization. */ -#ifdef USE_TIMES - ticks_to_nanosec = TICKS_TO_NANOSEC; -#endif -#ifdef USE_CLOCK - clocks_to_nanosec = CLOCKS_TO_NANOSEC; -#endif } /* Class timer's destructor. */ @@ -621,8 +518,6 @@ timer::validate_phases (FILE *fp) const { unsigned int /* timevar_id_t */ id; const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed; - uint64_t phase_user = 0; - uint64_t phase_sys = 0; uint64_t phase_wall = 0; size_t phase_ggc_mem = 0; static char phase_prefix[] = "phase "; @@ -637,26 +532,15 @@ timer::validate_phases (FILE *fp) const if (startswith (tv->name, phase_prefix)) { - phase_user += tv->elapsed.user; - phase_sys += tv->elapsed.sys; phase_wall += tv->elapsed.wall; phase_ggc_mem += tv->elapsed.ggc_mem; } } - if (phase_user > total->user - || phase_sys > total->sys - || phase_wall > total->wall - || phase_ggc_mem > total->ggc_mem) + if (phase_wall > total->wall || phase_ggc_mem > total->ggc_mem) { fprintf (fp, "Timing error: total of phase timers exceeds total time.\n"); - if (phase_user > total->user) - fprintf (fp, "user %13" PRIu64 " > %13" PRIu64 "\n", - phase_user, total->user); - if (phase_sys > total->sys) - fprintf (fp, "sys %13" PRIu64 " > %13" PRIu64 "\n", - phase_sys, total->sys); if (phase_wall > total->wall) fprintf (fp, "wall %13" PRIu64 " > %13" PRIu64 "\n", phase_wall, total->wall); @@ -680,20 +564,6 @@ timer::print_row (FILE *fp, /* The timing variable name. */ fprintf (fp, " %-35s:", name); -#ifdef HAVE_USER_TIME - /* Print user-mode time for this process. */ - fprintf (fp, "%7.2f (%3.0f%%)", - nanosec_to_floating_sec (elapsed.user), - percent_of (total->user, elapsed.user)); -#endif /* HAVE_USER_TIME */ - -#ifdef HAVE_SYS_TIME - /* Print system-mode time for this process. */ - fprintf (fp, "%7.2f (%3.0f%%)", - nanosec_to_floating_sec (elapsed.sys), - percent_of (total->sys, elapsed.sys)); -#endif /* HAVE_SYS_TIME */ - #ifdef HAVE_WALL_TIME /* Print wall clock time elapsed. */ fprintf (fp, "%7.2f (%3.0f%%)", @@ -718,9 +588,7 @@ timer::all_zero (const timevar_time_def &elapsed) { /* 5000000 nanosec == 5e-3 seconds. */ uint64_t tiny = 5000000; - return (elapsed.user < tiny - && elapsed.sys < tiny - && elapsed.wall < tiny + return (elapsed.wall < tiny && elapsed.ggc_mem < GGC_MEM_BOUND); } @@ -732,7 +600,7 @@ void timer::print (FILE *fp) { /* Only print stuff if we have some sort of time information. */ -#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME) +#if defined (HAVE_WALL_TIME) unsigned int /* timevar_id_t */ id; const timevar_time_def *total = &m_timevars[TV_TOTAL].elapsed; struct timevar_time_def now; @@ -754,8 +622,7 @@ timer::print (FILE *fp) TIMEVAR. */ m_start_time = now; - fprintf (fp, "\n%-35s%16s%14s%14s%14s\n", "Time variable", "usr", "sys", - "wall", "GGC"); + fprintf (fp, "\n%-35s%16s%14s\n", "Time variable", "wall", "GGC"); if (m_jit_client_items) fputs ("GCC items:\n", fp); for (id = 0; id < (unsigned int) TIMEVAR_LAST; ++id) @@ -809,15 +676,7 @@ timer::print (FILE *fp) /* Print total time. */ fprintf (fp, " %-35s:", "TOTAL"); -#ifdef HAVE_USER_TIME - fprintf (fp, "%7.2f ", nanosec_to_floating_sec (total->user)); -#endif -#ifdef HAVE_SYS_TIME - fprintf (fp, "%8.2f ", nanosec_to_floating_sec (total->sys)); -#endif -#ifdef HAVE_WALL_TIME - fprintf (fp, "%8.2f ", nanosec_to_floating_sec (total->wall)); -#endif + fprintf (fp, "%7.2f ", nanosec_to_floating_sec (total->wall)); fprintf (fp, PRsa (7) "\n", SIZE_AMOUNT (total->ggc_mem)); if (CHECKING_P || flag_checking) @@ -829,8 +688,7 @@ timer::print (FILE *fp) fprintf (fp, "Configure with --enable-checking=release to enable checks.\n"); #endif -#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) - || defined (HAVE_WALL_TIME) */ +#endif /* defined (HAVE_WALL_TIME) */ validate_phases (fp); } @@ -842,8 +700,6 @@ json::object * make_json_for_timevar_time_def (const timevar_time_def &ttd) { json::object *obj = new json::object (); - obj->set_float ("user", nanosec_to_floating_sec (ttd.user)); - obj->set_float ("sys", nanosec_to_floating_sec (ttd.sys)); obj->set_float ("wall", nanosec_to_floating_sec (ttd.wall)); obj->set_integer ("ggc_mem", ttd.ggc_mem); return obj; @@ -898,8 +754,7 @@ timer::timevar_def::make_json () const json::value * timer::make_json () const { - /* Only generate stuff if we have some sort of time information. */ -#if defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) || defined (HAVE_WALL_TIME) +#if defined (HAVE_WALL_TIME) json::object *report_obj = new json::object (); json::array *json_arr = new json::array (); report_obj->set ("timevars", json_arr); @@ -958,11 +813,9 @@ timer::make_json () const return report_obj; -#else /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) - || defined (HAVE_WALL_TIME) */ +#else /* defined (HAVE_USER_TIME) */ return NULL; -#endif /* defined (HAVE_USER_TIME) || defined (HAVE_SYS_TIME) - || defined (HAVE_WALL_TIME) */ +#endif /* !defined (HAVE_WALL_TIME) */ } /* Get the name of the topmost item. For use by jit for validating diff --git a/gcc/timevar.h b/gcc/timevar.h index c1fe2b5d543..970ac53ce2a 100644 --- a/gcc/timevar.h +++ b/gcc/timevar.h @@ -24,9 +24,7 @@ namespace json { class value; } /* Timing variables are used to measure elapsed time in various - portions of the compiler. Each measures elapsed user, system, and - wall-clock time, as appropriate to and supported by the host - system. + portions of the compiler. Each measures wall time. Timing variables are defined using the DEFTIMEVAR macro in timevar.def. Each has an enumeral identifier, used when referring @@ -53,12 +51,6 @@ namespace json { class value; } struct timevar_time_def { - /* User time in this process. */ - uint64_t user; - - /* System time (if applicable for this host platform) in this process. */ - uint64_t sys; - /* Wall clock time. */ uint64_t wall;