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

[Mark Wachsler]

-benchmark_all separately measures time spent encoding video, decoding
video, encoding audio, and decoding audio. You can't do that with
/usr/bin/time.

It is true that -benchmark could be replaced with /usr/bin/time, but that's
always been true. It seemed to make sense to -benchmark and -benchmark_all
continue to measure the same things.

Regards,
Mark

On Thu, Apr 26, 2018 at 12:28 PM, wm4 <nfxjfg at googlemail.com> wrote:

> On Fri, 20 Apr 2018 16:21:13 -0400
> Mark Wachsler <wachsler-at-google.com at ffmpeg.org> 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]);
>
> Is there any reason you you can't just use /usr/bin/time?
> _______________________________________________
> ffmpeg-devel mailing list
> ffmpeg-devel at ffmpeg.org
> http://ffmpeg.org/mailman/listinfo/ffmpeg-devel
>