[FFmpeg-devel] [PATCH] Add system and real time to benchmarking.

[Mark Wachsler]

Ping.

On Fri, Apr 20, 2018 at 4:21 PM, Mark Wachsler <wachsler at google.com> wrote:

> The -benchmark and -benchmark_all options now show user, system, and real
> time,
> instead of just user time.
> ---
>  fftools/ffmpeg.c | 50 ++++++++++++++++++++++++++++++++++--------------
>  1 file changed, 36 insertions(+), 14 deletions(-)
>
> diff --git a/fftools/ffmpeg.c b/fftools/ffmpeg.c
> index 4dbe72186d..d37171d567 100644
> --- a/fftools/ffmpeg.c
> +++ b/fftools/ffmpeg.c
> @@ -120,8 +120,14 @@ const char *const forced_keyframes_const_names[] = {
>      NULL
>  };
>
> +typedef struct TimeStamps {
> +  int64_t real_usec;
> +  int64_t user_usec;
> +  int64_t sys_usec;
> +} TimeStamps;
> +
>  static void do_video_stats(OutputStream *ost, int frame_size);
> -static int64_t getutime(void);
> +static TimeStamps get_time_stamps(void);
>  static int64_t getmaxrss(void);
>  static int ifilter_has_all_input_formats(FilterGraph *fg);
>
> @@ -133,7 +139,7 @@ static int64_t decode_error_stat[2];
>
>  static int want_sdp = 1;
>
> -static int current_time;
> +static TimeStamps current_time;
>  AVIOContext *progress_avio = NULL;
>
>  static uint8_t *subtitle_out;
> @@ -653,7 +659,7 @@ static void abort_codec_experimental(AVCodec *c, int
> encoder)
>  static void update_benchmark(const char *fmt, ...)
>  {
>      if (do_benchmark_all) {
> -        int64_t t = getutime();
> +        TimeStamps t = get_time_stamps();
>          va_list va;
>          char buf[1024];
>
> @@ -661,7 +667,11 @@ static void update_benchmark(const char *fmt, ...)
>              va_start(va, fmt);
>              vsnprintf(buf, sizeof(buf), fmt, va);
>              va_end(va);
> -            av_log(NULL, AV_LOG_INFO, "bench: %8"PRIu64" %s \n", t -
> current_time, buf);
> +            av_log(NULL, AV_LOG_INFO,
> +                   "bench: %8" PRIu64 " user %8" PRIu64 " sys %8" PRIu64
> " real %s \n",
> +                   t.user_usec - current_time.user_usec,
> +                   t.sys_usec - current_time.sys_usec,
> +                   t.real_usec - current_time.real_usec, buf);
>          }
>          current_time = t;
>      }
> @@ -4715,23 +4725,30 @@ static int transcode(void)
>      return ret;
>  }
>
> -
> -static int64_t getutime(void)
> -{
> +static TimeStamps get_time_stamps(void) {
> +  TimeStamps time_stamps;
> +  time_stamps.real_usec = av_gettime_relative();
>  #if HAVE_GETRUSAGE
>      struct rusage rusage;
>
>      getrusage(RUSAGE_SELF, &rusage);
> -    return (rusage.ru_utime.tv_sec * 1000000LL) + rusage.ru_utime.tv_usec;
> +    time_stamps.user_usec =
> +        (rusage.ru_utime.tv_sec * 1000000LL) + rusage.ru_utime.tv_usec;
> +    time_stamps.sys_usec =
> +        (rusage.ru_stime.tv_sec * 1000000LL) + rusage.ru_stime.tv_usec;
>  #elif HAVE_GETPROCESSTIMES
>      HANDLE proc;
>      FILETIME c, e, k, u;
>      proc = GetCurrentProcess();
>      GetProcessTimes(proc, &c, &e, &k, &u);
> -    return ((int64_t) u.dwHighDateTime << 32 | u.dwLowDateTime) / 10;
> +    time_stamps.user_usec =
> +        ((int64_t)u.dwHighDateTime << 32 | u.dwLowDateTime) / 10;
> +    time_stamps.sys_usec =
> +        ((int64_t)k.dwHighDateTime << 32 | k.dwLowDateTime) / 10;
>  #else
> -    return av_gettime_relative();
> +    time_stamps.user_usec = time_stamps.sys_usec = 0;
>  #endif
> +    return time_stamps;
>  }
>
>  static int64_t getmaxrss(void)
> @@ -4759,7 +4776,7 @@ static void log_callback_null(void *ptr, int level,
> const char *fmt, va_list vl)
>  int main(int argc, char **argv)
>  {
>      int i, ret;
> -    int64_t ti;
> +    TimeStamps ti;
>
>      init_dynload();
>
> @@ -4811,12 +4828,17 @@ int main(int argc, char **argv)
>              want_sdp = 0;
>      }
>
> -    current_time = ti = getutime();
> +    current_time = ti = get_time_stamps();
>      if (transcode() < 0)
>          exit_program(1);
> -    ti = getutime() - ti;
>      if (do_benchmark) {
> -        av_log(NULL, AV_LOG_INFO, "bench: utime=%0.3fs\n", ti /
> 1000000.0);
> +      current_time = get_time_stamps();
> +      int64_t utime = current_time.user_usec - ti.user_usec;
> +      int64_t stime = current_time.sys_usec - ti.sys_usec;
> +      int64_t rtime = current_time.real_usec - ti.real_usec;
> +      av_log(NULL, AV_LOG_INFO,
> +             "bench: utime=%0.3fs stime=%0.3fs rtime=%0.3fs\n",
> +             utime / 1000000.0, stime / 1000000.0, rtime / 1000000.0);
>      }
>      av_log(NULL, AV_LOG_DEBUG, "%"PRIu64" frames successfully decoded,
> %"PRIu64" decoding errors\n",
>             decode_error_stat[0], decode_error_stat[1]);
> --
> 2.17.0.484.g0c8726318c-goog
>
>