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 <akim.demai...@gmail.com> 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 <a...@lrde.epita.fr> + + 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 <a...@lrde.epita.fr> 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); }