Re: [PATCH] MI: new timing command

Nick Roberts
2006-12-31T07:47:07Z

Daniel Jacobowitz writes:
> On Sun, Dec 31, 2006 at 06:13:50PM +1300, Nick Roberts wrote:
> > > The autoconf manual has information about this sort of thing. I see
> > > that libiberty guards it, sometimes with HAVE_GETRUSAGE and other times
> > > with that and HAVE_SYS_RESOURCE_H.
> > >
> > > Will libiberty's get_run_time suffice for whatever you were doing,
> > > Nick?
> >
> > The manual says:
> >
> > -- Replacement: long get_run_time (void)
> > Returns the time used so far, in microseconds. If possible, this
> > is the time used by this process, else it is the elapsed time
> > since the process started.
> >
> > Without looking at the code, I would guess it's just a wrapper for getrusage
> > and it uses something like gettimeofday for elapsed time when it can't find
> > it. I think if user time isn't available it's best just to make
> > -enable-timings fail, so I'll use Eli's suggestion.
>
> In that case you can copy the necessary guards from that file.
> However, it does more than just getrusage - it also supports
> platforms with times() but without getrusage, which IIRC includes
> Windows, so it might be better to use it.

But as a last resort it returns elapsed time which would be wrong.

> I was wondering if we should make this a normal GDB setting, and use5C
> "-gdb-set mi profiling on" to enable it. There's already a maint
> setting to do the same thing for the CLI.

The command "maint set profiling on" is relevant for both CLI and MI,
whereas -enable-timings only works in MI.

Here's a new patch which also follows some of Vladimir's suggestions. If
approved I'll also regenerate and commit configure and config.in using GNU
Autoconf 2.59.

--
Nick http://www.inet.net.nz/~nickrob

2006-12-31 Nick Roberts <nickrob@snap.net.nz>

Based on work by Apple Computer, Inc.

* configure.ac: Test for sys/resource.h and getrusage.

* mi/mi-main.c: Include <sys/resource.h> if present.
(current_command_ts, do_timings): New static variables.
(timestamp, print_diff_now, print_diff, timeval_diff):
New static timing functions.
(mi_cmd_enable_timings): New function for new MI command.
(captured_mi_execute_command, mi_execute_async_cli_command):
Call timing functions.

* mi/mi-cmds.c (mi_cmds): Add entry for new MI command
-enable-timings.

* mi/mi-cmds.h (mi_cmd_enable_timings): New extern.

* mi/mi-parse.h: Include <sys/resource.h> if present.
(mi_timestamp): New structure.
(mi_parse): Add mi_timestamp* member.

Index: configure.ac
===================================================================
RCS file: /cvs/src/src/gdb/configure.ac,v
retrieving revision 1.36
diff -c -p -r1.36 configure.ac
*** configure.ac 22 Nov 2006 17:34:15 -0000 1.36
--- configure.ac 31 Dec 2006 07:39:10 -0000
*************** AC_CHECK_HEADERS(sys/file.h)
*** 355,360 ****
--- 355,361 ----
AC_CHECK_HEADERS(sys/filio.h)
AC_CHECK_HEADERS(sys/ioctl.h)
AC_CHECK_HEADERS(sys/param.h)
+ AC_CHECK_HEADERS(sys/resource.h)
AC_CHECK_HEADERS(sys/proc.h, [], [],
[#if HAVE_SYS_PARAM_H
# include <sys/param.h>
*************** AC_FUNC_ALLOCA
*** 442,447 ****
--- 443,449 ----
AC_FUNC_MMAP
AC_FUNC_VFORK
AC_CHECK_FUNCS(canonicalize_file_name realpath)
+ AC_CHECK_FUNCS(getrusage)
AC_CHECK_FUNCS(getuid getgid)
AC_CHECK_FUNCS(poll)
AC_CHECK_FUNCS(pread64)
Index: mi/mi-cmds.c
===================================================================
RCS file: /cvs/src/src/gdb/mi/mi-cmds.c,v
retrieving revision 1.21
diff -c -p -r1.21 mi-cmds.c
*** mi/mi-cmds.c 5 Jul 2006 19:03:47 -0000 1.21
--- mi/mi-cmds.c 31 Dec 2006 07:39:11 -0000
*************** struct mi_cmd mi_cmds[] =
*** 58,63 ****
--- 58,64 ----
{ "display-enable", { NULL, 0 }, NULL, NULL },
{ "display-insert", { NULL, 0 }, NULL, NULL },
{ "display-list", { NULL, 0 }, NULL, NULL },
+ { "enable-timings", { NULL, 0 }, 0, mi_cmd_enable_timings},
{ "environment-cd", { NULL, 0 }, 0, mi_cmd_env_cd},
{ "environment-directory", { NULL, 0 }, 0, mi_cmd_env_dir},
{ "environment-path", { NULL, 0 }, 0, mi_cmd_env_path},
Index: mi/mi-cmds.h
===================================================================
RCS file: /cvs/src/src/gdb/mi/mi-cmds.h,v
retrieving revision 1.19
diff -c -p -r1.19 mi-cmds.h
*** mi/mi-cmds.h 23 Dec 2005 18:57:46 -0000 1.19
--- mi/mi-cmds.h 31 Dec 2006 07:39:11 -0000
*************** extern mi_cmd_argv_ftype mi_cmd_data_lis
*** 72,77 ****
--- 72,78 ----
extern mi_cmd_argv_ftype mi_cmd_data_read_memory;
extern mi_cmd_argv_ftype mi_cmd_data_write_memory;
extern mi_cmd_argv_ftype mi_cmd_data_write_register_values;
+ extern mi_cmd_argv_ftype mi_cmd_enable_timings;
extern mi_cmd_argv_ftype mi_cmd_env_cd;
extern mi_cmd_argv_ftype mi_cmd_env_dir;
extern mi_cmd_argv_ftype mi_cmd_env_path;
Index: mi/mi-main.c
===================================================================
RCS file: /cvs/src/src/gdb/mi/mi-main.c,v
retrieving revision 1.86
diff -c -p -r1.86 mi-main.c
*** mi/mi-main.c 17 Nov 2006 19:30:41 -0000 1.86
--- mi/mi-main.c 31 Dec 2006 07:39:14 -0000
***************
*** 50,55 ****
--- 50,59 ----
#include <ctype.h>
#include <sys/time.h>

+ #if defined HAVE_SYS_RESOURCE_H
+ #include <sys/resource.h>
+ #endif
+
enum
{
FROM_TTY = 0
*************** struct captured_mi_execute_command_args
*** 81,86 ****
--- 85,96 ----
int mi_debug_p;
struct ui_file *raw_stdout;

+ /* This is used to pass the current command timestamp
+ down to continuation routines. */
+ static struct mi_timestamp *current_command_ts;
+
+ static int do_timings = 0;
+
/* The token of the last asynchronous command */
static char *last_async_command;
static char *previous_async_command;
*************** static int get_register (int regnum, int
*** 103,108 ****
--- 113,123 ----
layer that calls libgdb. Any operation used in the below should be
formalized. */

+ static void timestamp (struct mi_timestamp *tv);
+
+ static void print_diff_now (struct mi_timestamp *start);
+ static void print_diff (struct mi_timestamp *start, struct mi_timestamp *end);
+
enum mi_cmd_result
mi_cmd_gdb_exit (char *command, char **argv, int argc)
{
*************** mi_cmd_exec_continue (char *args, int fr
*** 194,200 ****
}

/* Interrupt the execution of the target. Note how we must play around
! with the token varialbes, in order to display the current token in
the result of the interrupt command, and the previous execution
token when the target finally stops. See comments in
mi_cmd_execute. */
--- 209,215 ----
}

/* Interrupt the execution of the target. Note how we must play around
! with the token variables, in order to display the current token in
the result of the interrupt command, and the previous execution
token when the target finally stops. See comments in
mi_cmd_execute. */
*************** mi_cmd_data_write_memory (char *command,
*** 1024,1029 ****
--- 1039,1073 ----
return MI_CMD_DONE;
}

+ enum mi_cmd_result
+ mi_cmd_enable_timings (char *command, char **argv, int argc)
+ {
+ #ifdef HAVE_GETRUSAGE
+ if (argc == 0)
+ do_timings = 1;
+ else if (argc == 1)
+ {
+ if (strcmp (argv[0], "yes") == 0)
+ do_timings = 1;
+ else if (strcmp (argv[0], "no") == 0)
+ do_timings = 0;
+ else
+ goto usage_error;
+ }
+ else
+ goto usage_error;
+
+ return MI_CMD_DONE;
+
+ usage_error:
+ error ("mi_cmd_enable_timings: Usage: %s {yes|no}", command);
+ return MI_CMD_ERROR;
+ #else
+ error ("GDB compiled without getrusage");
+ return MI_CMD_ERROR;
+ #endif
+ }
+
/* Execute a command within a safe environment.
Return <0 for error; >=0 for ok.

*************** captured_mi_execute_command (struct ui_o
*** 1038,1043 ****
--- 1082,1089 ----
(struct captured_mi_execute_command_args *) data;
struct mi_parse *context = args->command;

+ struct mi_timestamp cmd_finished;
+
switch (context->op)
{

*************** captured_mi_execute_command (struct ui_o
*** 1052,1059 ****
--- 1098,1112 ----
indication of what action is required and then switch on
that. */
args->action = EXECUTE_COMMAND_DISPLAY_PROMPT;
+
+ if (do_timings)
+ current_command_ts = context->cmd_start;
+
args->rc = mi_cmd_execute (context);

+ if (do_timings)
+ timestamp (&cmd_finished);
+
if (!target_can_async_p () || !target_executing)
{
/* print the result if there were no errors
*************** captured_mi_execute_command (struct ui_o
*** 1068,1073 ****
--- 1121,1130 ----
fputs_unfiltered ("^done", raw_stdout);
mi_out_put (uiout, raw_stdout);
mi_out_rewind (uiout);
+ /* Have to check cmd_start, since the command could be
+ -enable-timings. */
+ if (do_timings && context->cmd_start)
+ print_diff (context->cmd_start, &cmd_finished);
fputs_unfiltered ("\n", raw_stdout);
}
else if (args->rc == MI_CMD_ERROR)
*************** mi_execute_command (char *cmd, int from_
*** 1163,1168 ****
--- 1220,1233 ----
if (command != NULL)
{
struct gdb_exception result;
+
+ if (do_timings)
+ {
+ command->cmd_start = (struct mi_timestamp *)
+ xmalloc (sizeof (struct mi_timestamp));
+ timestamp (command->cmd_start);
+ }
+
/* FIXME: cagney/1999-11-04: Can this use of catch_exceptions either
be pushed even further down or even eliminated? */
args.command = command;
*************** mi_execute_async_cli_command (char *mi,
*** 1350,1355 ****
--- 1415,1422 ----
fputs_unfiltered ("*stopped", raw_stdout);
mi_out_put (uiout, raw_stdout);
mi_out_rewind (uiout);
+ if (do_timings)
+ print_diff_now (current_command_ts);
fputs_unfiltered ("\n", raw_stdout);
return MI_CMD_QUIET;
}
*************** _initialize_mi_main (void)
*** 1466,1468 ****
--- 1533,1572 ----
DEPRECATED_REGISTER_GDBARCH_SWAP (old_regs);
deprecated_register_gdbarch_swap (NULL, 0, mi_setup_architecture_data);
}
+
+ static void
+ timestamp (struct mi_timestamp *tv)
+ {
+ #ifdef HAVE_GETRUSAGE
+ gettimeofday (&tv->wallclock, NULL);
+ getrusage (RUSAGE_SELF, &tv->rusage);
+ #endif
+ }
+
+ static void
+ print_diff_now (struct mi_timestamp *start)
+ {
+ struct mi_timestamp now;
+ timestamp (&now);
+ print_diff (start, &now);
+ }
+
+ static long
+ timval_diff (struct timeval start, struct timeval end)
+ {
+ return ((end.tv_sec - start.tv_sec) * 1000000) +
+ (end.tv_usec - start.tv_usec);
+ }
+
+ static void
+ print_diff (struct mi_timestamp *start, struct mi_timestamp *end)
+ {
+ fprintf_unfiltered
+ (raw_stdout,
+ ",time={wallclock=\"%0.5f\",user=\"%0.5f\",system=\"%0.5f\"}",
+ timval_diff (start->wallclock, end->wallclock) / 1000000.0,
+ timval_diff (start->rusage.ru_utime, end->rusage.ru_utime) /
+ 1000000.0,
+ timval_diff (start->rusage.ru_stime, end->rusage.ru_stime) /
+ 1000000.0);
+ }
Index: mi/mi-parse.h
===================================================================
RCS file: /cvs/src/src/gdb/mi/mi-parse.h,v
retrieving revision 1.5
diff -c -p -r1.5 mi-parse.h
*** mi/mi-parse.h 23 Dec 2005 18:57:46 -0000 1.5
--- mi/mi-parse.h 31 Dec 2006 07:39:14 -0000
***************
*** 24,29 ****
--- 24,37 ----

/* MI parser */

+ #include <sys/resource.h>
+
+ /* Timestamps for current command and last asynchronous command */
+ struct mi_timestamp {
+ struct timeval wallclock;
+ struct rusage rusage;
+ };
+
enum mi_command_type
{
MI_COMMAND, CLI_COMMAND
*************** struct mi_parse
*** 35,40 ****
--- 43,49 ----
char *command;
char *token;
const struct mi_cmd *cmd;
+ struct mi_timestamp *cmd_start;
char *args;
char **argv;
int argc;