On Wed, Oct 9, 2024 at 6:18 PM Andi Kleen <[email protected]> wrote:
>
> From: Andi Kleen <[email protected]>
>
> 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.
OK for trunk if there's no serious objection until mid next week.
Richard.
> This removes a lot of code in timevar.cc:
>
> gcc/timevar.cc | 167
> ++++++---------------------------------------------------
> gcc/timevar.h | 10 +---
>
> 2 files changed, 17 insertions(+), 160 deletions(-)
>
> Bootstrapped on x86_64-linux with full test suite run.
>
> 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.
>
> ---
>
> v2: Adjust JSON/Sarif output too.
> v3: Make unconditional.
> ---
> 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 68bcf44864f9..4a57e74230d3 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;
> -#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;
> +#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_CLOCK
> - now->user = clock () * clocks_to_nanosec;
> +#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
> - }
> }
>
> /* 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 c1fe2b5d5439..970ac53ce2a6 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;
>
> --
> 2.46.2
>
