Re: [RFC] Fix MI timings

[Vladimir Prus <vladimir at codesourcery dot com>]

On Tuesday 10 March 2009 00:10:05 Vladimir Prus wrote:
> I've noticed that -enable-timings produces broken output for all
> commands that resume target. First, we output *stopped.
> And them on a separate line we print the timing, like this:
>
> 	,time={wallclock="0.32046",user="0.32000",system="0.00000"} (gdb)
>
> This happens because mi_on_normal_stop does print newline, and then
> mi_execute_async_cli_command does timings separately. This patch:
>
> 1. Make mi_on_normal_stop emit the timing info
> 2. Stop mi_execute_async_cli_command from doing so
> 3. Makes captured_mi_execute_command report timing both to MI
> and CLI code paths.
>
> I'll commit this in a few days if there are no objections.

*This* patch.

- Volodya

diff --git a/gdb/mi/mi-interp.c b/gdb/mi/mi-interp.c
index 65c1b4f..5ab5036 100644
--- a/gdb/mi/mi-interp.c
+++ b/gdb/mi/mi-interp.c
@@ -362,6 +362,7 @@ mi_on_normal_stop (struct bpstats *bs, int print_frame)
   fputs_unfiltered ("*stopped", raw_stdout);
   mi_out_put (mi_uiout, raw_stdout);
   mi_out_rewind (mi_uiout);
+  print_timing_maybe ();
   fputs_unfiltered ("\n", raw_stdout);
   gdb_flush (raw_stdout);
 }
diff --git a/gdb/mi/mi-main.c b/gdb/mi/mi-main.c
index b905a9e..a41c135 100644
--- a/gdb/mi/mi-main.c
+++ b/gdb/mi/mi-main.c
@@ -97,6 +97,8 @@ 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);
+void print_timing_maybe ();
+
 
 void
 mi_cmd_gdb_exit (char *command, char **argv, int argc)
@@ -1139,7 +1141,8 @@ captured_mi_execute_command (struct ui_out *uiout, void *data)
 {
   struct mi_parse *context = (struct mi_parse *) data;
 
-  struct mi_timestamp cmd_finished;
+  if (do_timings)
+    current_command_ts = context->cmd_start;
 
   running_result_record_printed = 0;
   switch (context->op)
@@ -1151,14 +1154,9 @@ captured_mi_execute_command (struct ui_out *uiout, void *data)
 	fprintf_unfiltered (raw_stdout, " token=`%s' command=`%s' args=`%s'\n",
 			    context->token, context->command, context->args);
 
-      if (do_timings)
-	current_command_ts = context->cmd_start;
 
       mi_cmd_execute (context);
 
-      if (do_timings)
-	timestamp (&cmd_finished);
-
       /* Print the result if there were no errors.
 
 	 Remember that on the way out of executing a command, you have
@@ -1174,10 +1172,7 @@ captured_mi_execute_command (struct ui_out *uiout, void *data)
 			    ? "^connected" : "^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);
+	  print_timing_maybe ();
 	  fputs_unfiltered ("\n", raw_stdout);
 	}
       else
@@ -1212,7 +1207,8 @@ captured_mi_execute_command (struct ui_out *uiout, void *data)
 		fputs_unfiltered ("^done", raw_stdout);
 		mi_out_put (uiout, raw_stdout);
 		mi_out_rewind (uiout);
-		fputs_unfiltered ("\n", raw_stdout);
+		print_timing_maybe ();
+		fputs_unfiltered ("\n", raw_stdout);		
 	      }
 	    else
 	      mi_out_rewind (uiout);
@@ -1447,8 +1443,6 @@ mi_execute_async_cli_command (char *cli_command, char **argv, int argc)
       /* Do this before doing any printing.  It would appear that some
          print code leaves garbage around in the buffer.  */
       do_cleanups (old_cleanups);
-      if (do_timings)
-      	print_diff_now (current_command_ts);
     }
 }
 
@@ -1567,6 +1561,15 @@ print_diff_now (struct mi_timestamp *start)
     print_diff (start, &now);
   }
 
+void
+print_timing_maybe ()
+{
+  // If the command is -enable-timing then do_timings may be
+  // true whilst current_command_ts is not initialized.
+  if (do_timings && current_command_ts)
+    print_diff_now (current_command_ts);
+}
+
 static long 
 timeval_diff (struct timeval start, struct timeval end)
   {
diff --git a/gdb/mi/mi-main.h b/gdb/mi/mi-main.h
index 977579e..6766d71 100644
--- a/gdb/mi/mi-main.h
+++ b/gdb/mi/mi-main.h
@@ -30,5 +30,7 @@ extern char *current_token;
 
 extern int running_result_record_printed;
 
+void print_timing_maybe ();
+
 #endif