Fix the overlapped prompt seen when we stop after continue and step

[mg11]

Summary

This patch was produced by Shawn Best to fix the issue where the (lldb) prompt is overwritten at times after lldb stops. The code has been tested a lot on linux 64 bit by Matthew Gardiner, and partially reviewed by Greg Clayton. It would be good to test it on OSX, and if ok, get it submitted.

[emaste]

I would have liked to reproduce the prompt race condition again and then verify this fix, but unfortunately am now unable to reproduce it on FreeBSD. In any case, LLDB still behaves as expected with this patch.

include/lldb/Target/Process.h

2667

It's the only purpose of this, yes?

2679

Do we anticipate different callers needing different timeouts? It seems to me the timeout ought to just be set in SyncIOHandler itself.

source/Commands/CommandObjectProcess.cpp

781

We probably don't need this comment at each SyncIOHandler() call, and in any case race condition no longer exists with the SyncIOHandler call there.

source/Target/Process.cpp

908

This log (the !timed_out case) will spam the log quite a bit, and seems unnecessary (or perhaps include it in verbose); the timed_out case above is definitely important though.

[tfiala]

Ok, thanks Matthew. I'll run it through OSX and my Linux. I'll get it in
if it looks good.

I thought I caught the tail end of the thread and that maybe you saw issues
with it in some process states (e.g. attaching or something like that?).
Was it not an issue, or was it just not worse than it was before?

[tfiala]

(Ed - clearly the fact that we have a patch that might address this has spooked the behavior on FreeBSD so it no longer shows --- wish that worked the same for Linux from time to time! :-P)

[emaste]

Yep, the unfortunate nature of race conditions :(

In any case, in case I wasn't clear: I do believe this patch should go in, and it looks good to me other than the minor nits I commented on.

This issue is the one item that held me back from updating the copy of LLDB in the FreeBSD base system and so am very happy to see it fixed.

[tfiala]

Verified on:
Ubuntu 14.04 x86_64, clang-built lldb. All tests passed.
MacOSX 10.9.4, Xcode 6 Beta 5-built lldb. All tests passed.

[tfiala]

svn commit
Sending include/lldb/Target/Process.h
Sending source/Commands/CommandObjectProcess.cpp
Sending source/Commands/CommandObjectThread.cpp
Sending source/Target/Process.cpp
Sending source/Target/Target.cpp
Transmitting file data .....
Committed revision 215446.

[mg11]

Replying to Ed's review.

I agree regarding the SyncIOHandler function signature. It should be parameterless, and the timeout value should be a value private to this routine. And yes, the "success" log statement is unnecessary noise.

include/lldb/Target/Process.h

public:
     // is set to the event which triggered the stop. If wait_always = false,
     // and the process is already stopped, this function returns immediately.
     lldb::StateType
     WaitForProcessToStop (const TimeValue *timeout,
                           lldb::EventSP *event_sp_ptr = NULL,
                           bool wait_always = true,
                           Listener *hijack_listener = NULL);
 
+
+    //--------------------------------------------------------------------------------------
+    /// Waits for the process state to be running within a given msec timeout.
+    ///
+    /// The main purpose of this is to implement an interlock waiting for HandlePrivateEvent
+    /// to push an IOHandler.
+    ///
+    /// @param[in] timeout_msec
+    ///     The maximum time length to wait for the process to transition to the
+    ///     eStateRunning state, specified in milliseconds.
+    ///
+    /// @return
+    ///     true if successfully signalled that process started and IOHandler pushes, false
+    ///     if it timed out.
+    //--------------------------------------------------------------------------------------
+    bool
+    SyncIOHandler (uint64_t timeout_msec);
+
+
     lldb::StateType
     WaitForStateChangedEvents (const TimeValue *timeout,
                                lldb::EventSP &event_sp,
                                Listener *hijack_listener); // Pass NULL to use builtin listener
     
     Event *
     PeekAtStateChangedEvents ();
     
protected:
     lldb::ABISP                 m_abi_sp;
     lldb::IOHandlerSP           m_process_input_reader;
     Communication               m_stdio_communication;
     Mutex                       m_stdio_communication_mutex;
     std::string                 m_stdout_data;
     std::string                 m_stderr_data;
     Mutex                       m_profile_data_comm_mutex;
     std::vector<std::string>    m_profile_data;
+    Predicate<bool>             m_iohandler_sync;
     MemoryCache                 m_memory_cache;
     AllocatedMemoryCache        m_allocated_memory_cache;
     bool                        m_should_detach;   /// Should we detach if the process object goes away with an explicit call to Kill or Detach?
     LanguageRuntimeCollection   m_language_runtimes;
     std::unique_ptr<NextEventAction> m_next_event_action_ap;
     std::vector<PreResumeCallbackAndBaton> m_pre_resume_actions;
     ProcessRunLock              m_public_run_lock;
     ProcessRunLock              m_private_run_lock;

source/Commands/CommandObjectProcess.cpp

DoExecute (Args& command, CommandReturnObject &result)
 
                 // Set the actions that the threads should each take when resuming
                 for (uint32_t idx=0; idx<num_threads; ++idx)
                 {
                     const bool override_suspend = false;
                     process->GetThreadList().GetThreadAtIndex(idx)->SetResumeState (eStateRunning, override_suspend);
                 }
             }
-            
             Error error(process->Resume());
+
             if (error.Success())
             {
+                // There is a race condition where this thread will return up the call stack to the main command
+                // handler and show an (lldb) prompt before HandlePrivateEvent (from PrivateStateThread) has
+                // a chance to call PushProcessIOHandler().
+                process->SyncIOHandler(2000);
+
                 result.AppendMessageWithFormat ("Process %" PRIu64 " resuming\n", process->GetID());
                 if (synchronous_execution)
                 {
                     state = process->WaitForProcessToStop (NULL);
 
                     result.SetDidChangeProcessState (true);
                     result.AppendMessageWithFormat ("Process %" PRIu64 " %s\n", process->GetID(), StateAsCString (state));
                     result.SetStatus (eReturnStatusSuccessFinishNoResult);

source/Commands/CommandObjectThread.cpp

DoExecute (Args& command, CommandReturnObject &result)
                 if (new_plan_sp->SetIterationCount(m_options.m_step_count))
                 {
                     result.AppendWarning ("step operation does not support iteration count.");
                 }
             }
 
             process->GetThreadList().SetSelectedThreadByID (thread->GetID());
             process->Resume ();
-        
+            // There is a race condition where this thread will return up the call stack to the main command handler
+            // and show an (lldb) prompt before HandlePrivateEvent (from PrivateStateThread) has
+            // a chance to call PushProcessIOHandler().
+            process->SyncIOHandler(2000);
 
             if (synchronous_execution)
             {
                 StateType state = process->WaitForProcessToStop (NULL);
                 
                 //EventSP event_sp;
                 //StateType state = process->WaitForStateChangedEvents (NULL, event_sp);
                 //while (! StateIsStoppedState (state))

source/Target/Process.cpp

Process::Process(Target &target, Listener &listener) :
     m_abi_sp (),
     m_process_input_reader (),
     m_stdio_communication ("process.stdio"),
     m_stdio_communication_mutex (Mutex::eMutexTypeRecursive),
     m_stdout_data (),
     m_stderr_data (),
     m_profile_data_comm_mutex (Mutex::eMutexTypeRecursive),
     m_profile_data (),
+    m_iohandler_sync (false),
     m_memory_cache (*this),
     m_allocated_memory_cache (*this),
     m_should_detach (false),
     m_next_event_action_ap(),
     m_public_run_lock (),
     m_private_run_lock (),
     m_currently_handling_event(false),
     m_finalize_called(false),
Process::GetNextEvent (EventSP &event_sp)
     StateType state = eStateInvalid;
 
     if (m_listener.GetNextEventForBroadcaster (this, event_sp) && event_sp)
         state = Process::ProcessEventData::GetStateFromEvent (event_sp.get());
 
     return state;
 }
 
+bool
+Process::SyncIOHandler (uint64_t timeout_msec)
+{
+    bool timed_out = false;
+
+    // don't sync (potentially context switch) in case where there is no process IO
+    if (m_process_input_reader)
+    {
+        TimeValue timeout = TimeValue::Now();
+        timeout.OffsetWithMicroSeconds(timeout_msec*1000);
+
+        m_iohandler_sync.WaitForValueEqualTo(true, &timeout, &timed_out);
+
+        Log *log(lldb_private::GetLogIfAllCategoriesSet (LIBLLDB_LOG_PROCESS));
+        if(log)
+        {
+            if(timed_out)
+                log->Printf ("Process::%s pid %" PRIu64 " (timeout=%" PRIu64 "ms): FAIL", __FUNCTION__, GetID (), timeout_msec);
+            else
+                log->Printf ("Process::%s pid %" PRIu64 ": SUCCESS", __FUNCTION__, GetID ());
+        }
+
+        // reset sync one-shot so it will be ready for next time
+        m_iohandler_sync.SetValue(false, eBroadcastNever);
+    }
+
+    return !timed_out;
+}
 
 StateType
 Process::WaitForProcessToStop (const TimeValue *timeout, lldb::EventSP *event_sp_ptr, bool wait_always, Listener *hijack_listener)
 {
     // We can't just wait for a "stopped" event, because the stopped event may have restarted the target.
     // We have to actually check each event, and in the case of a stopped event check the restarted flag
     // on the event.
     if (event_sp_ptr)
if (should_broadcast)
         }
         Process::ProcessEventData::SetUpdateStateOnRemoval(event_sp.get());
         if (StateIsRunningState (new_state))
         {
             // Only push the input handler if we aren't fowarding events,
             // as this means the curses GUI is in use...
             if (!GetTarget().GetDebugger().IsForwardingEvents())
                 PushProcessIOHandler ();
+            m_iohandler_sync.SetValue(true, eBroadcastAlways);
         }
         else if (StateIsStoppedState(new_state, false))
         {
+            m_iohandler_sync.SetValue(false, eBroadcastNever);
             if (!Process::ProcessEventData::GetRestartedFromEvent(event_sp.get()))
             {
                 // If the lldb_private::Debugger is handling the events, we don't
                 // want to pop the process IOHandler here, we want to do it when
                 // we receive the stopped event so we can carefully control when
                 // the process IOHandler is popped because when we stop we want to
                 // display some text stating how and why we stopped, then maybe some
                 // process/thread/frame info, and then we want the "(lldb) " prompt

source/Target/Target.cpp

if (error.Success())
             StateType state = m_process_sp->WaitForProcessToStop (NULL, NULL, false, hijack_listener_sp.get());
             
             if (state == eStateStopped)
             {
                 if (!synchronous_execution)
                     m_process_sp->RestoreProcessEvents ();
 
                 error = m_process_sp->PrivateResume();
-    
                 if (error.Success())
                 {
+                    // there is a race condition where this thread will return up the call stack to the main command
+                    // handler and show an (lldb) prompt before HandlePrivateEvent (from PrivateStateThread) has
+                    // a chance to call PushProcessIOHandler()
+                    m_process_sp->SyncIOHandler(2000);
+
                     if (synchronous_execution)
                     {
                         state = m_process_sp->WaitForProcessToStop (NULL, NULL, true, hijack_listener_sp.get());
                         const bool must_be_alive = false; // eStateExited is ok, so this must be false
                         if (!StateIsStoppedState(state, must_be_alive))
                         {
                             error.SetErrorStringWithFormat("process isn't stopped: %s", StateAsCString(state));
                         }