Re: timevar: 2/3: improve the output format

[Akim Demaille]

I have used the format you suggested to display the times.  I’m
not sure we should specify the resolution, it kinda of is displayed
by the figures themselves, but I’ll do whatever you suggest Bruno.
However, see 3/3 before.


commit 17bf1247ef4a64e6400df5206bbe570889ef252f
Author: Akim Demaille <address@hidden>
Date:   Thu Oct 11 22:15:36 2018 +0200

    timevar: improve the output format
    
    From:
    
        Execution times (seconds)
         reader                :   0,01 ( 3%) usr   0,00 (16%) sys   0,00 ( 0%) 
wall
         outputting report     :   0,03 ( 6%) usr   0,00 (15%) sys   0,00 ( 0%) 
wall
         parser action tables  :   0,02 ( 4%) usr   0,00 ( 2%) sys   0,00 ( 0%) 
wall
         outputting parser     :   0,01 ( 2%) usr   0,00 (13%) sys   0,00 ( 0%) 
wall
         running m4            :   0,37 (84%) usr   0,00 (50%) sys   0,00 ( 0%) 
wall
         total time            :   0,44             0,01             0,00
    
    To:
    
        Execution times (seconds)
                                  CPU user      CPU system    wall clock
         reader                   0,020 ( 4%)   0,002 ( 9%)   0,000000 ( 0%)
         outputting report        0,029 ( 6%)   0,002 (11%)   0,000000 ( 0%)
         parser action tables     0,020 ( 4%)   0,001 ( 6%)   0,000000 ( 0%)
         outputting parser        0,014 ( 3%)   0,002 (10%)   0,000000 ( 0%)
         running m4               0,431 (83%)   0,012 (59%)   0,000000 ( 0%)
         total time               0,522         0,020         0,000000
    
    Suggested by Bruno Haible.
    See https://lists.gnu.org/archive/html/bug-gnulib/2018-10/msg00040.html.
    
    * lib/timevar.c (timevar_print): Use %7.3f for usr/sys and %11.6f for
    wall, since its resolution is much higher.

diff --git a/ChangeLog b/ChangeLog
index d93c7b6b0..369848b12 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,11 @@
+2018-10-12  Akim Demaille  <address@hidden>
+
+       timevar: improve the output format
+       Suggested by Bruno Haible.
+       See https://lists.gnu.org/archive/html/bug-gnulib/2018-10/msg00040.html.
+       * lib/timevar.c (timevar_print): Use %7.3f for usr/sys and %11.6f for
+       wall, since its resolution is much higher.
+
 2018-10-12  Akim Demaille  <address@hidden>
 
        timevar: expect that getrusage is available.
diff --git a/lib/timevar.c b/lib/timevar.c
index 469db9cb1..8b574e277 100644
--- a/lib/timevar.c
+++ b/lib/timevar.c
@@ -304,7 +304,10 @@ timevar_print (FILE *fp)
 
   struct timevar_time_def const* total = &timevars[tv_total].elapsed;
 
-  fputs (_("\nExecution times (seconds)\n"), fp);
+  fprintf (fp, "%-22s\n",
+           _("Execution times (seconds)"));
+  fprintf (fp, " %-22s   %-13s %-13s %-16s\n",
+           "", _("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];
@@ -327,20 +330,20 @@ timevar_print (FILE *fp)
         continue;
 
       /* The timing variable name.  */
-      fprintf (fp, " %-22s:", tv->name);
+      fprintf (fp, " %-22s", tv->name);
 
       /* Print user-mode time for this process.  */
-      fprintf (fp, "%7.2f (%2.0f%%) usr",
+      fprintf (fp, "%8.3f (%2.0f%%)",
                tv->elapsed.user,
                (total->user == 0 ? 0 : tv->elapsed.user / total->user) * 100);
 
       /* Print system-mode time for this process.  */
-      fprintf (fp, "%7.2f (%2.0f%%) sys",
+      fprintf (fp, "%8.3f (%2.0f%%)",
                tv->elapsed.sys,
                (total->sys == 0 ? 0 : tv->elapsed.sys / total->sys) * 100);
 
       /* Print wall clock time elapsed.  */
-      fprintf (fp, "%7.2f (%2.0f%%) wall",
+      fprintf (fp, "%11.6f (%2.0f%%)",
                tv->elapsed.wall,
                (total->wall == 0 ? 0 : tv->elapsed.wall / total->wall) * 100);
 
@@ -348,8 +351,8 @@ timevar_print (FILE *fp)
     }
 
   /* Print total time.  */
-  fprintf (fp, " %-22s:", timevars[tv_total].name);
-  fprintf (fp, "%7.2f          ", total->user);
-  fprintf (fp, "%7.2f          ", total->sys);
-  fprintf (fp, "%7.2f\n", total->wall);
+  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);
 }