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

Greg Clayton gclayton at apple.com
Fri May 8 11:47:43 PDT 2015


> 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