[RFC] Broken -thread-info output in non-stop mode.

[RFC] Broken -thread-info output in non-stop mode.

[Pedro Alves]

Hi guys,

I've run across this broken MI output in non-stop mode:

 -thread-info
 =thread-created,id="2",group-id="32"
 ~"[New Thread 32.32801]\n"
 ^running
 *running,thread-id="2"
 (gdb)

Note that we have output ^running instead of ^done, and, that
the ",threads=..." part is completelly missing.  I was expecting
something like this instead:

 -thread-info
 =thread-created,id="2",group-id="32"
 *running,thread-id="2"
 ^done,threads=[{id="2",target-id="...",details="...",state="running"},{id="1",...,frame={...},state="stopped"}]

-thread-info, is calling target_find_new_threads, and ... that is
finding new threads.  In non-stop mode, threads we find this way
have to be running, otherwise we'd have seen a stop reply for
them already, hence, we call set_running on them.  Then, the problem
is that we decide to output ^running instead of ^done in the
mi_on_resume observer.  This observer is called from inside the
threads.c:set_running function.  So, we're here:

static void
mi_on_resume (ptid_t ptid)
{
  /* To cater for older frontends, emit ^running, but do it only once
     per each command.  We do it here, since at this point we know
     that the target was successfully resumed, and in non-async mode,
     we won't return back to MI interpreter code until the target
     is done running, so delaying the output of "^running" until then
     will make it impossible for frontend to know what's going on.

     In future (MI3), we'll be outputting "^done" here.  */
  if (!running_result_record_printed)
    {
      if (current_token)
	fputs_unfiltered (current_token, raw_stdout);
      fputs_unfiltered ("^running\n", raw_stdout);
    }

Coming from here:

#0  mi_on_resume (ptid={pid = 32, lwp = 0, tid = 32801})
    at mi/mi-interp.c:389
#1  0x0805049a in observer_target_resumed_notification_stub (data=0x8093339, args_data=0xffffce30)
    at ./observer.inc:422
#2  0x0804fd6b in generic_observer_notify (subject=0x83cb870, args=0xffffce30)
    at gdb/observer.c:166
#3  0x08050524 in observer_notify_target_resumed (ptid={pid = 32, lwp = 0, tid = 32801}) at ./observer.inc:447
#4  0x080fadf4 in set_running (ptid={pid = 32, lwp = 0, tid = 32801}, running=1)
    at gdb/thread.c:524
#5  0x0806c5de in remote_add_thread (currthread={pid = 32, lwp = 0, tid = 32801}, running=1)
    at gdb/remote.c:1154
#5  0x0806c5de in remote_notice_new_inferior (currthread={pid = 32, lwp = 0, tid = 32801}, running=1)
    at gdb/remote.c:1213
#6  0x0806dd41 in remote_threads_info ()
    at remote.c:2247
#7  0x080fb406 in print_thread_info (uiout=0x83c3670, requested_thread=-1, pid=-1)
    at gdb/thread.c:712
#8  0x08093d60 in mi_cmd_thread_info (command=0x84ba8e0 "thread-info", argv=0x83dc4a8, argc=0)
    at mi/mi-main.c:347

The "^running" output was moved to the observer by this change:

 http://sourceware.org/ml/gdb-patches/2008-06/msg00247.html

I've been trying to find a way to fix this without changing the
MI output, but it is tricky at best.  In sync mode, we can not delay
printing the "^running" bit until the current command is done, as that
would be too late --- that's the main reason it is done on the
observer.  In async mode, however, I think we can, by instead of
outputting "^running" immediatly in the observer, setting a flag claiming
any thread was resumed, and then when the command finishes, we output
the "^running" instead of "^done".  In async mode, the MI resumption commands
are always asynchronous, so when the command is finished the target is still
running, unlike in sync mode.  See patch below --- although it becomes a
misnomer, I'm reusing the "running_result_record_printed" flag for
exactly this.  This somewhat fixes the broken output I shown at the top
of this email, but, it still leaves a "^running" where I don't
think we want it at all, see:

 -thread-info
 =thread-created,id="2",group-id="32"
 *running,thread-id="2"
 ^running,threads=[{id="2",target-id="...",details="...",state="running"},{id="1",...,frame={...},state="stopped"}]
 ^^^^^^^^

For -thread-info, that should always be "^done", I believe.  

 "^done" [ "," results ]
     The synchronous operation was successful, results are the return values.

 "^running"
     The asynchronous operation was successfully started. The target is running. 

I kind of only expect ^running on resumption commands (-exec-run,
-exec-step, -exec-next, etc.).  The docs mention "asynchronous
operation", although we do output it for synchronous resumptions ...

          ( My interpretation of the docs is that in SYNC mode, -exec-step
            should output a ^done, when the step is complete, and the target
            stops; while in ASYNC mode, -exec-step would output an
            immediate ^running.  But, that's not how it works... anyway,
            moving on.  )

Any suggestions on this?  One way I was thinking was to split the
"this thread is running because we just resumed it"
from "this thread was already running" set_running calls, and pass
that information down to the observer, but, I'm not sure that will
fix it completelly.  In multi-process, we may even find a new
process when we do a -thread-info, and we may end up doing an internal
stop/resume bit, thus breaking the output again.

My next bet is to still do what the patch below does, but in addition,
never output "^running" if the command was a "-thread-info", similarly
to the hack in place that checks for "target-select".  Or the other way
around, white list which commands want ^running instead of ^done --- AFAIK,
only the resumption commands are expected to output ^running: -exec-run,
-exec-step, -exec-next, etc.  For MI3, when we completelly get rid of "^running",
the hack could go away.  This would leave CLI commands issued from
MI to solve --- "info threads" would still output ^running...  
It is a problem?  I'm guessing it would be, but I'm not sure.

The patch at:

 http://sourceware.org/ml/gdb-patches/2008-06/msg00247.html

... claimed that it is a bonus.  Is it really a bonus, in that would
any frontend really expect it?  Given that CLI commands didn't output
^running for close to 10 years, how bad would it be if we reverted
back to not doing it again, at least for async targets?

Any other suggestions?

-- 
Pedro Alves

---
 gdb/mi/mi-interp.c |    2 +-
 gdb/mi/mi-main.c   |   23 +++++++++++++++++++++--
 2 files changed, 22 insertions(+), 3 deletions(-)

Index: src/gdb/mi/mi-interp.c
===================================================================
--- src.orig/gdb/mi/mi-interp.c	2009-03-15 17:11:00.000000000 +0000
+++ src/gdb/mi/mi-interp.c	2009-03-15 17:30:58.000000000 +0000
@@ -378,7 +378,7 @@ mi_on_resume (ptid_t ptid)
      will make it impossible for frontend to know what's going on.
 
      In future (MI3), we'll be outputting "^done" here.  */
-  if (!running_result_record_printed)
+  if (!running_result_record_printed && !target_is_async_p ())
     {
       if (current_token)
 	fputs_unfiltered (current_token, raw_stdout);
Index: src/gdb/mi/mi-main.c
===================================================================
--- src.orig/gdb/mi/mi-main.c	2009-03-15 17:11:00.000000000 +0000
+++ src/gdb/mi/mi-main.c	2009-03-15 17:37:16.000000000 +0000
@@ -1165,7 +1165,18 @@ captured_mi_execute_command (struct ui_o
 	 to directly use the mi_interp's uiout, since the command could 
 	 have reset the interpreter, in which case the current uiout 
 	 will most likely crash in the mi_out_* routines.  */
-      if (!running_result_record_printed)
+      if (running_result_record_printed && target_is_async_p ())
+	{
+	  fputs_unfiltered (context->token, raw_stdout);
+	  /* There's no particularly good reason why target-connect results
+	     in not ^done.  Should kill ^connected for MI3.  */
+	  fputs_unfiltered (strcmp (context->command, "target-select") == 0
+			    ? "^connected" : "^running", raw_stdout);
+	  mi_out_put (uiout, raw_stdout);
+	  mi_out_rewind (uiout);
+	  fputs_unfiltered ("\n", raw_stdout);
+	}
+      else if (!running_result_record_printed)
 	{
 	  fputs_unfiltered (context->token, raw_stdout);
 	  /* There's no particularly good reason why target-connect results
@@ -1203,7 +1214,15 @@ captured_mi_execute_command (struct ui_o
 	    || current_interp_named_p (INTERP_MI2)
 	    || current_interp_named_p (INTERP_MI3))
 	  {
-	    if (!running_result_record_printed)
+	    if (running_result_record_printed && target_is_async_p ())
+	      {
+		fputs_unfiltered (context->token, raw_stdout);
+		fputs_unfiltered ("^running\n", raw_stdout);
+		mi_out_put (uiout, raw_stdout);
+		mi_out_rewind (uiout);
+		fputs_unfiltered ("\n", raw_stdout);
+	      }
+	    else if (!running_result_record_printed)
 	      {
 		fputs_unfiltered (context->token, raw_stdout);
 		fputs_unfiltered ("^done", raw_stdout);

Re: [RFC] Broken -thread-info output in non-stop mode.

[Vladimir Prus]

On Sunday 15 March 2009 21:25:13 Pedro Alves wrote:
> Hi guys,
>
> I've run across this broken MI output in non-stop mode:
>
>  -thread-info
>  =thread-created,id="2",group-id="32"
>  ~"[New Thread 32.32801]\n"
>  ^running
>  *running,thread-id="2"
>  (gdb)
>
> Note that we have output ^running instead of ^done, and, that
> the ",threads=..." part is completelly missing.  I was expecting
> something like this instead:
>
>  -thread-info
>  =thread-created,id="2",group-id="32"
>  *running,thread-id="2"
> 
> ^done,threads=[{id="2",target-id="...",details="...",state="running"},{id="
>1",...,frame={...},state="stopped"}]
>
> -thread-info, is calling target_find_new_threads, and ... that is
> finding new threads.  In non-stop mode, threads we find this way
> have to be running, otherwise we'd have seen a stop reply for
> them already, hence, we call set_running on them.  Then, the problem
> is that we decide to output ^running instead of ^done in the
> mi_on_resume observer.  

Well, there are two problems with the current output.

1. We output ^running as opposed to ^done.
2. When we decide to output ^running, we also discard anything uiout might
contain.

The possible ways to fix (1) are:
    - Special case -thread-info (in mi_on_resume) and output ^done.
	  This is easy. Won't help CLI "info thread" in non-stop mode.
    - Make resume observer distinguish between 'yes, this thread was
      explicitly resumed' and 'we've attached to a thread and found it's
      running'. How hard this would be?
    - Always output ^done, except for a few specially cased MI commands.
      
Speaking of (2), for the sync case it's is mi_on_resume that should print
^running, and if it printed ^running, then there's no way for 
captured_mi_execute_command to print anything while adhering to MI syntax.
So, if ^running was printed mistakenly, we're messed up. For async case,
you are right that ^running can be delayed, and in that case we can print
uiout. However, printing ^running instead of ^done is likely to confuse 
frontends. So, we still need to solve the ^running vs. ^done issue.


> For -thread-info, that should always be "^done", I believe.
>
>  "^done" [ "," results ]
>      The synchronous operation was successful, results are the return
> values.
>
>  "^running"
>      The asynchronous operation was successfully started. The target is
> running.
>
> I kind of only expect ^running on resumption commands (-exec-run,
> -exec-step, -exec-next, etc.).  The docs mention "asynchronous
> operation", although we do output it for synchronous resumptions ...
>
>           ( My interpretation of the docs is that in SYNC mode, -exec-step
>             should output a ^done, when the step is complete, and the
> target stops; while in ASYNC mode, -exec-step would output an immediate
> ^running.  But, that's not how it works... anyway, moving on.  )

The docs use 'async' to mean 'any command that resume the target'. Or,
an alternative interpretation is that the docs are written as if async
mode is the only possible mode ;-)

> Any suggestions on this?  One way I was thinking was to split the
> "this thread is running because we just resumed it"
> from "this thread was already running" set_running calls, and pass
> that information down to the observer, but, I'm not sure that will
> fix it completelly.  In multi-process, we may even find a new
> process when we do a -thread-info, and we may end up doing an internal
> stop/resume bit, thus breaking the output again.

Ouch. But wait, how is 'resume' is done? My impression was that all 
resumptions of the as direct result on user commands are done via
'proceed'. Looking at CVS HEAD, I see one use of proceed in 
proceed_after_attach_callback that I cannot immediately correlate with
a user command, but all others are clearly correlated. So, maybe MI
should output ^running only when proceed is called?

> My next bet is to still do what the patch below does, but in addition,
> never output "^running" if the command was a "-thread-info", similarly
> to the hack in place that checks for "target-select".  Or the other way
> around, white list which commands want ^running instead of ^done --- AFAIK,
> only the resumption commands are expected to output ^running: -exec-run,
> -exec-step, -exec-next, etc.  For MI3, when we completelly get rid of
> "^running", the hack could go away.  This would leave CLI commands issued
> from MI to solve --- "info threads" would still output ^running...
> It is a problem?  I'm guessing it would be, but I'm not sure.
>
> The patch at:
>
>  http://sourceware.org/ml/gdb-patches/2008-06/msg00247.html
>
> ... claimed that it is a bonus.  Is it really a bonus, in that would
> any frontend really expect it?  Given that CLI commands didn't output
> ^running for close to 10 years, how bad would it be if we reverted
> back to not doing it again, at least for async targets?

Well, they did not output ^running for 10 years, but it does not mean
it was bad. KDevelop users did complain that issuing CLI commands resulted
in no feedback that the application is actually running. We can suppress
this in async mode, but then the solution starts to include so many 
assumptions that it makes me nervous ;-) Let me know what you think about
the proceed idea.

- Volodya


>
> Any other suggestions?

Re: [RFC] Broken -thread-info output in non-stop mode.

[Pedro Alves]

On Monday 16 March 2009 09:49:18, Vladimir Prus wrote:
> On Sunday 15 March 2009 21:25:13 Pedro Alves wrote:

> Ouch. But wait, how is 'resume' is done? My impression was that all 
> resumptions of the as direct result on user commands are done via
> 'proceed'. Looking at CVS HEAD, I see one use of proceed in 
> proceed_after_attach_callback that I cannot immediately correlate with
> a user command, but all others are clearly correlated. So, maybe MI
> should output ^running only when proceed is called?

You're pretty much right.  If we need to carry the target a bit,
we'll only proceed it in a continuation, or call target_resume
directly.

> Well, they did not output ^running for 10 years, but it does not mean
> it was bad. KDevelop users did complain that issuing CLI commands resulted
> in no feedback that the application is actually running. We can suppress
> this in async mode, but then the solution starts to include so many 
> assumptions that it makes me nervous ;-) 

I take it you'll make KDevelop handle ^done + *running at some
point.  :-)

> Let me know what you think about 
> the proceed idea.

I like it, thanks!  I'm about to post a mini patch series
implementing it.  In the process I cleaned up a few things that
were sort of in the way.

-- 
Pedro Alves