[RFA, doc RFA] Include wallclock time in "maint time" output.

Doug Evans dje@google.com
Thu Nov 3 23:18:00 GMT 2011


On Tue, Sep 20, 2011 at 12:09 AM, Eli Zaretskii <eliz@gnu.org> wrote:
>> Date: Mon, 19 Sep 2011 23:08:52 -0700
>> From: Doug Evans <dje@google.com>
>> Cc: gdb-patches@sourceware.org
>>
>> > Actually, it would be much more useful to display time it took the
>> > inferior between two points where GDB gets control.  Are you trying to
>> > approximate that missing feature, or is there some other use case
>> > where wallclock time would be useful?
>>
>> It's not always the case that the inferior is running when wanting to
>> see wallclock time.  E.g., remote protocol operations, excessive nfs
>> latency, etc.
>> [For reference sake, MI already supports this feature for monitoring
>> slow operations.]
>
> It sounds like it would be a good idea to mention these use cases in
> the manual.
>
>> It's not possible to implement gettimeofday on windows with better
>> accuracy?
>
> It is easy to do that with 10ms resolution, but not below that.  Below
> that, AFAIK only interval measurements are "easy" on Windows.
>
>> gettimeofday is pretty simple and standard,
>> inventing something new has its own disadvantages.
>
> I disagree, but I can live with that.
>
>> >> +If set to a nonzero value, @value{GDBN} will display how much time it
>> >>  took to execute each command, following the command's own output.
>> >> -The time is not printed for the commands that run the target, since
>> >> -there's no mechanism currently to compute how much time was spend
>> >> -by @value{GDBN} and how much time was spend by the program been debugged.
>> >> -it's not possibly currently
>> >
>> > I'm not sure we should remove that remark, because what it says is
>> > still true, even after your changes.
>>
>> The part about time not being printed for commands that run the target
>> is not true.
>
> The CPU time still accounts for GDB only, right?  It sounds like we
> interpret this sentence differently, so perhaps it should be reworded
> rather than being deleted.

You'll need to tell me how you interpret it.
Note that my docs do say that the time printed does not include
inferior time.

>> Does the part about there being no mechanism to compute how much time
>> was spent by the inferior really add anything of value?
>
> It explains the meaning of the times we print, IMO.  If someone saw
> the need to tell that at some point, I tend to honor that.

PTAL.

2011-11-03  Doug Evans  <dje@google.com>

        * utils.c: #include "timeval-utils.h".
        (cmd_stats): Rename start_time to start_cpu_time.
        New member start_wall_time.
        (report_command_stats): Report wall time.
        (make_command_stats_cleanup): Record start wall time.

        doc/
        * gdb.texinfo (Maintenance Commands): Update docs of "maint time".
-------------- next part --------------
2011-11-03  Doug Evans  <dje@google.com>

	* utils.c: #include "timeval-utils.h".
	(cmd_stats): Rename start_time to start_cpu_time.
	New member start_wall_time.
	(report_command_stats): Report wall time.
	(make_command_stats_cleanup): Record start wall time.

	doc/
	* gdb.texinfo (Maintenance Commands): Update docs of "maint time".

Index: utils.c
===================================================================
RCS file: /cvs/src/src/gdb/utils.c,v
retrieving revision 1.264
diff -u -p -r1.264 utils.c
--- utils.c	14 Oct 2011 07:55:26 -0000	1.264
+++ utils.c	3 Nov 2011 22:46:13 -0000
@@ -45,6 +45,7 @@
 #endif
 
 #include <signal.h>
+#include "timeval-utils.h"
 #include "gdbcmd.h"
 #include "serial.h"
 #include "bfd.h"
@@ -691,7 +692,8 @@ static int display_space;
 struct cmd_stats 
 {
   int msg_type;
-  long start_time;
+  long start_cpu_time;
+  struct timeval start_wall_time;
   long start_space;
 };
 
@@ -723,12 +725,18 @@ report_command_stats (void *arg)
 
   if (display_time)
     {
-      long cmd_time = get_run_time () - start_stats->start_time;
+      long cmd_time = get_run_time () - start_stats->start_cpu_time;
+      struct timeval now_wall_time, delta_wall_time;
+
+      gettimeofday (&now_wall_time, NULL);
+      timeval_sub (&delta_wall_time,
+		   &now_wall_time, &start_stats->start_wall_time);
 
       printf_unfiltered (msg_type == 0
-			 ? _("Startup time: %ld.%06ld\n")
-			 : _("Command execution time: %ld.%06ld\n"),
-			 cmd_time / 1000000, cmd_time % 1000000);
+			 ? _("Startup time: %ld.%06ld (cpu), %ld.%06ld (wall)\n")
+			 : _("Command execution time: %ld.%06ld (cpu), %ld.%06ld (wall)\n"),
+			 cmd_time / 1000000, cmd_time % 1000000,
+			 delta_wall_time.tv_sec, delta_wall_time.tv_usec);
     }
 
   if (display_space)
@@ -764,7 +772,8 @@ make_command_stats_cleanup (int msg_type
 #endif
 
   new_stat->msg_type = msg_type;
-  new_stat->start_time = get_run_time ();
+  new_stat->start_cpu_time = get_run_time ();
+  gettimeofday (&new_stat->start_wall_time, NULL);
 
   return make_cleanup_dtor (report_command_stats, new_stat, xfree);
 }
Index: doc/gdb.texinfo
===================================================================
RCS file: /cvs/src/src/gdb/doc/gdb.texinfo,v
retrieving revision 1.888
diff -u -p -r1.888 gdb.texinfo
--- doc/gdb.texinfo	3 Nov 2011 14:32:49 -0000	1.888
+++ doc/gdb.texinfo	3 Nov 2011 23:16:16 -0000
@@ -32991,13 +32991,16 @@ switch (@pxref{Mode Options}).
 @kindex maint time
 @cindex time of command execution
 @item maint time
-Control whether to display the execution time for each command.  If
-set to a nonzero value, @value{GDBN} will display how much time it
+Control whether to display the execution time of @value{GDBN} for each command.
+If set to a nonzero value, @value{GDBN} will display how much time it
 took to execute each command, following the command's own output.
-The time is not printed for the commands that run the target, since
-there's no mechanism currently to compute how much time was spend
-by @value{GDBN} and how much time was spend by the program been debugged.
-it's not possibly currently 
+Both cpu time and wallclock time are printed.
+Printing both is useful when trying to determine whether the cost is
+cpu or, e.g., disk/network, latency.
+Note that the cpu time printed is for @value{GDBN} only, it does not include
+the execution time of the inferior because there's no mechanism currently
+to compute how much time was spent by @value{GDBN} and how much time was
+spent by the program been debugged.
 This can also be requested by invoking @value{GDBN} with the
 @option{--statistics} command-line switch (@pxref{Mode Options}).
 


More information about the Gdb-patches mailing list