[lldb-dev] Process::SyncIOHandler(), everyone please try out the following patch

Pavel Labath labath at google.com
Mon May 11 07:21:35 PDT 2015


Hello,

What you are describing could be part of the problem, but it is not
the issue that I have been experiencing. What happens in my case is
the following:
1. main thread finishes processing the "step-over" command and begins
reading the next one, blocking in a select() inside IOHandlerEditline
2. private state thread processes the eStateRunning event and pushes a
IOHandlerProcessSTDIO on the handler stack

The pushing of the handler happens here:

void
Debugger::PushIOHandler (const IOHandlerSP& reader_sp)
{
    if (!reader_sp)
        return;

    // Got the current top input reader...
    IOHandlerSP top_reader_sp (m_input_reader_stack.Top());

    // Don't push the same IO handler twice...
    if (reader_sp.get() != top_reader_sp.get())
    {
        // Push our new input reader
        m_input_reader_stack.Push (reader_sp);

        // Interrupt the top input reader to it will exit its Run() function
        // and let this new input reader take over
        if (top_reader_sp)
            top_reader_sp->Deactivate();
    }
}

However, nothing in this function causes the main thread to exit the
Editline handler. Deactivate() merely sets a flag, but it does not
wake the main thread up - it remains stuck waiting for a command. In
fact, when LLDB is in this wrong-prompt state, I can enter a LLDB
command and it will be processed even though ProcessSTDIO is the top
handler.

I believe we should make sure that after we push a new handler to the
top, the old one stops being used. I tried changing this function to
do a top_reader_sp->Cancel() after the Deactivate() call. The
situation improves: the output then looks like
(lldb) ^C
xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

It's not completely ideal, but it's an improvement over the previous
situation. However, this does not seem to solve the problem
completely, as I am still getting the wrong prompt sometimes, albeit
less often. This leads me to think there is another issue here,
probably the one you are describing, but I have not diagnosed this
yet. I wil keep digging...


BTW, I've noticed that PushIOHandler does not lock
m_input_reader_stack.GetMutex(), unlike PopIOHandler, and all other
functions which deal with handlers. Is that intentional? I think it
should lock the mutex as well.

cheers,
pl

On 8 May 2015 at 19:47, Greg Clayton <gclayton at apple.com> wrote:
>
>> On May 8, 2015, at 7:52 AM, Pavel Labath <labath at google.com> wrote:
>>
>> Hello,
>>
>> so I have taken a look at this again, and I have found that at the
>> point where we call  `m_top->Hide()`, m_top is actually pointing to
>> IOHandlerProcessSTDIO and *not* IOHandlerEditline. This obviously
>> means that the output does not get hidden.
>>
> Interesting. This is what should happen, and there should be nothing to hide if the IOHandlerProcessSTDIO is still active.
>
> Sounds like we need to stop any IOHandlers from being activated while we are doing async output. The command interpreter thread is probably allowing the command interpreter to be activated while async output is coming out and this causes the command prompt to be printed...
>
> What we want to happen is:
>
> - event handling thread: wants to display async output, it tells the top IOHandler to hide, prints the output, then tells the top IOHandler to refresh itself.
> - command interpreter thread: should not be able activate a IOHandler while async IO is going on (but it currently is and is causing the prompt to come out and incorrect times)
>
> Both the above things are able to happen at the same time and they shouldn't. Somehow when we do async output we need to make a lock that prevents this. The code that runs the current IOHandlers looks like:
>
>
> void
> Debugger::ExecuteIOHandlers()
> {
>
>     while (1)
>     {
>         IOHandlerSP reader_sp(m_input_reader_stack.Top());
>         if (!reader_sp)
>             break;
>
>         reader_sp->Activate();
>         reader_sp->Run();
>         reader_sp->Deactivate();
>
>         // Remove all input readers that are done from the top of the stack
>         while (1)
>         {
>             IOHandlerSP top_reader_sp = m_input_reader_stack.Top();
>             if (top_reader_sp && top_reader_sp->GetIsDone())
>                 m_input_reader_stack.Pop();
>             else
>                 break;
>         }
>     }
>     ClearIOHandlers();
> }
>
> So if the IOHandlerProcessSTDIO was active, it must would be in the "reader_sp->Run();" line above in the command interpreter thread. It must be returning from Run() when it is popped and then the command interpreter should call activate and then Run() which will cause the "(lldb) " prompt to show up. So we need some synchronization before the reader_sp->Activate() like:
>
>
>         m_input_reader_stack.CompleteAsyncIO();
>         reader_sp->Activate();
>         reader_sp->Run();
>         reader_sp->Deactivate();
>
> But I don't see how this thread would allow a new IOHandler to activate itself in the first place because it takes the IOHandlerStack::m_mutex:
>
> void
> IOHandlerStack::PrintAsync (Stream *stream, const char *s, size_t len)
> {
>     if (stream)
>     {
>         Mutex::Locker locker (m_mutex);
>         if (m_top)
>         {
>             Mutex::Locker locker(m_top->GetOutputMutex());
>             const bool did_hide = m_top->Hide();
>             stream->Write (s, len);
>             stream->Flush();
>             if (did_hide)
>                 m_top->Refresh();
>         }
>     }
> }
>
> So my questions is how is the "m_input_reader_stack.Top()" and "m_input_reader_stack.Pop()" completing while we have this lock? It the IOHandlerStack::PrintAsync() takes the IOHandlerStack::m_mutex and should stop things from being popped...
>
>
>> At the moment when I enter  IOHandlerStack::PrintAsync, the main
>> thread has already finished its work is blocked in
>> lldb_private::Editline::GetCharacter. I'm suspecting that the process
>> I/O handler gets pushed on top of editline during one of the internal
>> process start-stop events that get handled as a part of the step-over
>> handling, but I have not confirmed this yet.
>>
>> I will continue investigating next week, but I am writing this now in
>> case you happen to know what the problem is or how to fix it. In any
>> case, have a nice weekend,
>> pl
>>
>>
>>
>>
>>
>> On 10 April 2015 at 21:04, Greg Clayton <gclayton at apple.com> wrote:
>>> Pavel,
>>>
>>> can you you look into why this is happening by adding logging to a file?
>>>
>>> What I believe should happen is:
>>>
>>> 1 - main thread: get the "n" command and issues the step and may or may not get back to printing the "(lldb) " prompt before step 2 below
>>> 2 - debugger event thread: calls Debugger::HandleProcessEvent to handle the eStateRunning event
>>> 3 - debugger event thread: might get STDOUT event for the "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx" text and async prints it
>>> 4 - debugger event thread: calls Debugger::HandleProcessEvent to handle the eStateStopped event
>>> 5 - debugger event thread: has async text for stop reason "thread #1:..." and async prints it
>>>
>>>
>>> For both async prints in step 3 and 5, we call IOHandler::Hide() which for the Editline should hide the "(lldb) " prompt, show the text and call IOHandler::Referesh() to show the prompt again and any partial command you may have typed. Why that is not happening the the question. When we display the async text we run this function:
>>>
>>>     1  void
>>>     2  IOHandlerStack::PrintAsync (Stream *stream, const char *s, size_t len)
>>>     3  {
>>>     4      if (stream)
>>>     5      {
>>>     6          Mutex::Locker locker (m_mutex);
>>>     7          if (m_top)
>>>     8          {
>>>     9              Mutex::Locker locker(m_top->GetOutputMutex());
>>>    10              const bool did_hide = m_top->Hide();
>>>    11              stream->Write (s, len);
>>>    12              stream->Flush();
>>>    13              if (did_hide)
>>>    14                  m_top->Refresh();
>>>    15          }
>>>    16      }
>>>    17  }
>>>
>>> Note above on line 10 we ask the editline IOHandler to hide itself, and then we write the data on line 11 and then _only_ if we hid the IOHandler to we ask it to refresh. So the question is, is the main thread printing the "(lldb) " prompt after line 10? Does your linux process have a ProcessIOHandler, or is ProcessGDBRemote getting the stdout via async 'O' packets?
>>>
>>> Greg
>>>
>>>> On Apr 10, 2015, at 3:12 AM, Pavel Labath <labath at google.com> wrote:
>>>>
>>>> Sadly, still not working on Linux :(
>>>>
>>>> Process 24525 stopped
>>>> * thread #1: tid = 24525, 0x000000000040075e a.out`main + 558 at
>>>> a.cc:33, name = 'a.out', stop reason = step over
>>>>   frame #0: 0x000000000040075e a.out`main + 558 at a.cc:33
>>>>  30      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  31      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  32      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>> -> 33      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  34      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  35      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  36      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>> (lldb) n
>>>> (lldb) xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
>>>> Process 24525 stopped
>>>> * thread #1: tid = 24525, 0x0000000000400772 a.out`main + 578 at
>>>> a.cc:34, name = 'a.out', stop reason = step over
>>>>   frame #0: 0x0000000000400772 a.out`main + 578 at a.cc:34
>>>>  31      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  32      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  33      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>> -> 34      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  35      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  36      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>>  37      printf("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx\n");
>>>> .....
>>>>
>>>>
>>>> --
>>>> pl
>>>>
>>>>
>>>> On 10 April 2015 at 01:06, Greg Clayton <gclayton at apple.com> wrote:
>>>>> Note that my "io2.patch" removed the fix that was introduced with 234517. So it works without that fix which is good news.
>>>>>
>>>>> When sourcing files we turn off output for many things. Try your commands as:
>>>>>
>>>>> % ~/Documents/src/lldb/tot/build/Debug/lldb -o 'file d:\testexe\simple_step.exe' -o 'break set -f simple_step.cpp -l 12' -o run -o bt
>>>>>
>>>>> The attached patch always uses the debugger output and error instead of the output and error from the current IOHandler. This shouldn't make a change, but it is the change I would want to submit.
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> Please test this as much as you can and let me know if this fixes all your prompt issues (besides stuff not showing up when run in non-interactive mode by sourcing a commands file).
>>>>>
>>>>> Greg
>>>>>
>>>>>> On Apr 9, 2015, at 4:44 PM, Zachary Turner <zturner at google.com> wrote:
>>>>>>
>>>>>> So my double prompt seems to be fixed, but then I reverted your change and noticed it was still fixed.  So I looked through the history a little bit, and it appears to have been fixed by r234517.  I still don't see the output of "bt" printed when it's run from my inside my .lldbinit file.  But since r234517 fixed my double prompt, I must be having the same problem described in the commit message, which is that I don't have an IOHandler on my process.  So maybe addressing that will fix my backtrace as well.
>>>>>>
>>>>>> Either way, if anyone else tries this patch and also notices that the problem is fixed, please also check whether it is fixed by 234517 without this patch so that we are sure what exactly is causing people's problems to go away.
>>>>>>
>>>>>> On Thu, Apr 9, 2015 at 4:05 PM Greg Clayton <gclayton at apple.com> wrote:
>>>>>> Try this one out and let me know if anything improves?
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>> On Apr 9, 2015, at 11:23 AM, Zachary Turner <zturner at google.com> wrote:
>>>>>>>
>>>>>>> If you need a VM or something let me know I can proabbly make something that you can remote into and is already properly set up and ready to build.
>>>>>>>
>>>>>>> On Thu, Apr 9, 2015 at 11:02 AM Greg Clayton <gclayton at apple.com> wrote:
>>>>>>> Thanks everyone for trying this out. I will modify this patch and try again soon.
>>>>>>>
>>>>>>>> On Apr 9, 2015, at 7:56 AM, Pavel Labath <labath at google.com> wrote:
>>>>>>>>
>>>>>>>> The situation is even worse on Linux, i'm afraid. Whereas I was
>>>>>>>> getting no wrong prompts before (at least when debugging locally), now
>>>>>>>> the prompt appears in the wrong place in about 10% of the cases.
>>>>>>>>
>>>>>>>> pl
>>>>>>>>
>>>>>>>> On 9 April 2015 at 15:19, Ed Maste <emaste at freebsd.org> wrote:
>>>>>>>>> On 8 April 2015 at 16:35, Greg Clayton <gclayton at apple.com> wrote:
>>>>>>>>>>
>>>>>>>>>> This one removes the m_iohandler_sync completely and coordinates async IO with the IOHandlers. Let me know if this works any better for freebsd, linux or windows.
>>>>>>>>>
>>>>>>>>> Problem persists with this version on FreeBSD, unfortunately:
>>>>>>>>>
>>>>>>>>> ...
>>>>>>>>> 165
>>>>>>>>> 166          (void)setlocale(LC_ALL, "");
>>>>>>>>> (lldb) step
>>>>>>>>> (lldb) Process 77191 stopped
>>>>>>>>> * thread #1: tid = 100853, 0x00000000004023fa ls`main(argc=1,
>>>>>>>>> argv=0x00007fffffffe588) + 42 at ls.c:166, stop reason = step in
>>>>>>>>>  frame #0: 0x00000000004023fa ls`main(argc=1,
>>>>>>>>> argv=0x00007fffffffe588) + 42 at ls.c:166
>>>>>>>>> 163          char *bp = tcapbuf;
>>>>>>>>> 164  #endif
>>>>>>>>> 165
>>>>>>>>> -> 166          (void)setlocale(LC_ALL, "");
>>>>>>>>> 167
>>>>>>>>> 168          /* Terminal defaults to -Cq, non-terminal defaults to -1. */
>>>>>>>>> 169          if (isatty(STDOUT_FILENO)) {
>>>>>>>>> step
>>>>>>>>> ...
>>>>>>>>> _______________________________________________
>>>>>>>>> lldb-dev mailing list
>>>>>>>>> lldb-dev at cs.uiuc.edu
>>>>>>>>> http://lists.cs.uiuc.edu/mailman/listinfo/lldb-dev
>>>>>>>
>>>>>>>
>>>>>>> _______________________________________________
>>>>>>> lldb-dev mailing list
>>>>>>> lldb-dev at cs.uiuc.edu
>>>>>>> http://lists.cs.uiuc.edu/mailman/listinfo/lldb-dev
>>>>>>
>>>>>
>>>>>
>>>
>




More information about the lldb-dev mailing list