Re: timevar: 3/3: use clock_gettime to get wall clock time

[Akim Demaille]

> Le 13 oct. 2018 à 08:43, Bruno Haible <address@hidden> a écrit :
> 
> Hi Akim,
> 
>>> I don’t know how 'gettime' compares against 'gethrxtime'.
>> 
>> gethrxtime is exactly what I need, thanks!  It does use gettime as
>> a fallback, after having tried better (accuracy and monotony) options.
> 
> Very nice!
> 
>> Here is my updated proposal.
> 
> Looks good, except for the mentioned points 2) - a 'float' with its 24 bits
> of precision is surely not enough to hold an ‘xtime_t' - and 3).

But it felt weird to use a double, the number of significant decimal digits
of a float (about 7) seems enough.  But I agree rounding errors are not
good.  Let’s keep xtime_t for the measurement, and just use floats when
displaying.  WDYT?

See below.


>>> 3) Link dependency: List the link dependencies, like it's done e.g. in
>>> the 'clock-time', 'gettime', and 'gethrxtime' modules. Also use these
>>> dependencies when linking the test program (in module ‘timevar-tests').
>> 
>> AFAICT, there are no direct link dependencies in timevar, only indirect
>> ones via the modules it depends upon.  What do you mean?
> 
> The 'Link' and 'Include' fields in a Gnulib module description are not
> evaluated by gnulib-tool. They are purely informative, for the user of the
> module.

Ok.

>> there are no direct link dependencies in timevar, only indirect
>> ones via the modules it depends upon.  What do you mean?
> 
> I mean that in this situation, the user of the module does not want to
> perform a recursive search across the dependencies of the module, to
> discover the link dependencies. That’s your job as author of the module.

Doh.  I was expecting gnulib-tool to do that.  Why doesn’t it?


commit 7fe573e0179b3c4492fcccef01e111a6b162eba9
Author: Akim Demaille <address@hidden>
Date:   Fri Oct 12 06:46:09 2018 +0200

    timevar: use gethrxtime to get wall clock time
    
    clock_gettime is not portable.  gethrxtime takes the best available
    option to get the wall clock time, including clock_gettime (monotonic
    clock), and gettime (non monotonic).
    Also, using xtime_t instead of float preserves the precision.
    Suggested by Bruno Haible.
    
    * modules/timevar (Depends-on): We need gethrxtime.
    We no longer use times().
    * lib/timevar.h (timevar_time_def): Use xtime_t.
    * lib/timevar.c (set_to_current_time): Use gethrxtime.
    Adjust all dependencies.

diff --git a/ChangeLog b/ChangeLog
index ecd69df04..7f5848a97 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,17 @@
+2018-10-13  Akim Demaille  <address@hidden>
+
+       timevar: use gethrxtime to get wall clock time
+       clock_gettime is not portable.  gethrxtime takes the best available
+       option to get the wall clock time, including clock_gettime (monotonic
+       clock), and gettime (non monotonic).
+       Also, using xtime_t instead of float preserves the precision.
+       Suggested by Bruno Haible.
+       * modules/timevar (Depends-on): We need gethrxtime.
+       We no longer use times().
+       * lib/timevar.h (timevar_time_def): Use xtime_t.
+       * lib/timevar.c (set_to_current_time): Use gethrxtime.
+       Adjust all dependencies.
+
 2018-10-13  Akim Demaille  <address@hidden>
 
        bootstrap: fix wget command for po files.
diff --git a/lib/timevar.c b/lib/timevar.c
index 8b574e277..937a944e9 100644
--- a/lib/timevar.c
+++ b/lib/timevar.c
@@ -30,6 +30,7 @@
 #include <sys/time.h>
 #include <sys/times.h>
 
+#include "gethrxtime.h"
 #include "gettext.h"
 #define _(msgid) gettext (msgid)
 #include "xalloc.h"
@@ -101,13 +102,27 @@ set_to_current_time (struct timevar_time_def *now)
   if (!timevar_enabled)
     return;
 
+  const suseconds_t giga = 1000 * 1000 * 1000;
+
   struct rusage rusage;
   getrusage (RUSAGE_SELF, &rusage);
-  now->user = rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
-  now->sys  = rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
+  xtime_t  usr_s  = rusage.ru_utime.tv_sec;
+  long int usr_ns = rusage.ru_utime.tv_usec * 1000;
+  time_t   sys_s  = rusage.ru_stime.tv_sec;
+  long int sys_ns = rusage.ru_stime.tv_usec * 1000;
+
   getrusage (RUSAGE_CHILDREN, &rusage);
-  now->user += rusage.ru_utime.tv_sec + rusage.ru_utime.tv_usec * 1e-6;
-  now->sys  += rusage.ru_stime.tv_sec + rusage.ru_stime.tv_usec * 1e-6;
+  usr_ns += rusage.ru_utime.tv_usec * 1000;
+  usr_s  += rusage.ru_utime.tv_sec + usr_ns / giga;
+  usr_ns %= giga;
+
+  sys_ns += rusage.ru_stime.tv_usec * 1000;
+  sys_s  += rusage.ru_stime.tv_sec + usr_ns / giga;
+  sys_ns %= giga;
+
+  now->user = xtime_make (usr_s, usr_ns);
+  now->sys  = xtime_make (sys_s, sys_ns);
+  now->wall = gethrxtime();
 }
 
 /* Return the current time.  */
@@ -303,6 +318,9 @@ timevar_print (FILE *fp)
   start_time = now;
 
   struct timevar_time_def const* total = &timevars[tv_total].elapsed;
+  const float total_usr = total->user * 1e-9;
+  const float total_sys = total->sys * 1e-9;
+  const float total_wall = total->wall * 1e-9;
 
   fprintf (fp, "%-22s\n",
            _("Execution times (seconds)"));
@@ -310,49 +328,50 @@ timevar_print (FILE *fp)
            "", _("CPU user"), _("CPU system"), _("wall clock"));
   for (unsigned /* timevar_id_t */ id = 0; id < (unsigned) TIMEVAR_LAST; ++id)
     {
-      struct timevar_def *tv = &timevars[(timevar_id_t) id];
-      const float tiny = 5e-3;
-
       /* Don't print the total execution time here; that goes at the
          end.  */
       if ((timevar_id_t) id == tv_total)
         continue;
 
       /* Don't print timing variables that were never used.  */
+      struct timevar_def *tv = &timevars[(timevar_id_t) id];
       if (!tv->used)
         continue;
 
+      const float usr = tv->elapsed.user * 1e-9;
+      const float sys = tv->elapsed.sys * 1e-9;
+      const float wall = tv->elapsed.wall * 1e-9;
+
       /* Don't print timing variables if we're going to get a row of
          zeroes.  */
-      if (tv->elapsed.user < tiny
-          && tv->elapsed.sys < tiny
-          && tv->elapsed.wall < tiny)
+      const float tiny = 5e-3;
+      if (usr < tiny && sys < tiny && wall < tiny)
         continue;
 
       /* The timing variable name.  */
       fprintf (fp, " %-22s", tv->name);
 
       /* Print user-mode time for this process.  */
-      fprintf (fp, "%8.3f (%2.0f%%)",
-               tv->elapsed.user,
-               (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
+      fprintf (fp, "%8.3f (%2lld%%)",
+               usr,
+               total->user == 0 ? 0 : tv->elapsed.user * 100 / total->user);
 
       /* Print system-mode time for this process.  */
-      fprintf (fp, "%8.3f (%2.0f%%)",
-               tv->elapsed.sys,
-               (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
+      fprintf (fp, "%8.3f (%2lld%%)",
+               sys,
+               total->sys == 0 ? 0 : tv->elapsed.sys * 100 / total->sys);
 
       /* Print wall clock time elapsed.  */
-      fprintf (fp, "%11.6f (%2.0f%%)",
-               tv->elapsed.wall,
-               (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
+      fprintf (fp, "%11.6f (%2lld%%)",
+               wall,
+               total_wall == 0 ? 0 : tv->elapsed.wall  * 100 / total->wall);
 
       putc ('\n', fp);
     }
 
   /* Print total time.  */
   fprintf (fp, " %-22s", timevars[tv_total].name);
-  fprintf (fp, "%8.3f      ", total->user);
-  fprintf (fp, "%8.3f      ", total->sys);
-  fprintf (fp, "%11.6f\n", total->wall);
+  fprintf (fp, "%8.3f      ", total_usr);
+  fprintf (fp, "%8.3f      ", total_sys);
+  fprintf (fp, "%11.6f\n", total_wall);
 }
diff --git a/lib/timevar.h b/lib/timevar.h
index ff443fed6..cf9e0830d 100644
--- a/lib/timevar.h
+++ b/lib/timevar.h
@@ -23,6 +23,8 @@
 
 # include <stdio.h>
 
+# include "xtime.h"
+
 # ifdef  __cplusplus
 extern "C" {
 # endif
@@ -58,14 +60,14 @@ extern "C" {
 struct timevar_time_def
 {
   /* User time in this process.  */
-  float user;
+  xtime_t user;
 
   /* System time (if applicable for this host platform) in this
      process.  */
-  float sys;
+  xtime_t sys;
 
   /* Wall clock time.  */
-  float wall;
+  xtime_t wall;
 };
 
 /* An enumeration of timing variable identifiers.  Constructed from
diff --git a/modules/timevar b/modules/timevar
index 354d1d211..b2a12bb99 100644
--- a/modules/timevar
+++ b/modules/timevar
@@ -6,12 +6,12 @@ lib/timevar.h
 lib/timevar.c
 
 Depends-on:
+gethrxtime
 getrusage
 gettext-h
 stdlib
 sys_time
 sys_times
-times
 xalloc
 
 Makefile.am:
@@ -20,6 +20,10 @@ lib_SOURCES += timevar.c timevar.def
 Include:
 "timevar.h"
 
+Link:
+$(LIB_GETHRXTIME)
+$(LTLIBINTL) when linking with libtool, $(LIBINTL) otherwise
+
 License:
 GPLv3+