thread state coordinator: add test to be explicit about resume behavior in presence of deferred stop notification still pending.

There is a state transition that seems potentially buggy that I am capturing and
logging here, and including an explicit test to demonstrate expected behavior.  See new test
for detailed description.  Added logging around this area since, if we hit it, we
may have a usage bug, or a new state transition we really need to investigate.

This is around this scenario:
Thread C deferred stop notification awaiting thread A and thread B to stop.
Thread A stops.
Thread A requests resume.
Thread B stops.

Here we will explicitly signal the deferred stop notification after thread B
stops even though thread A is now resumed.  Copious logging happens here.

llvm-svn: 218683
This commit is contained in:
Todd Fiala 2014-09-30 16:56:28 +00:00
parent 7a77075530
commit f8d929dc82
3 changed files with 137 additions and 9 deletions

View File

@ -499,3 +499,81 @@ TEST(ThreadStateCoordinatorTest, RequestThreadResumeIgnoresCallbackWhenThreadIsR
// The resume request should not have gone off because we think it is already running. // The resume request should not have gone off because we think it is already running.
ASSERT_EQ (0, resume_call_count); ASSERT_EQ (0, resume_call_count);
} }
TEST(ThreadStateCoordinatorTest, ResumedThreadAlreadyMarkedDoesNotHoldUpPendingStopNotification)
{
// We're going to test this scenario:
// * Deferred notification waiting on two threads, A and B. A and B currently running.
// * Thread A stops.
// * Thread A resumes.
// * Thread B stops.
//
// Here we could have forced A to stop again (after the Thread A resumes) because we had a pending stop nofication awaiting
// all those threads to stop. However, we are going to explicitly not try to restop A - somehow
// that seems wrong and possibly buggy since for that to happen, we would have intentionally called
// a resume after the stop. Instead, we'll just log and indicate this looks suspicous. We can revisit
// that decision after we see if/when that happens.
ThreadStateCoordinator coordinator(StdoutLogger);
const lldb::tid_t TRIGGERING_TID = 4105;
const lldb::tid_t PENDING_TID_A = 2;
const lldb::tid_t PENDING_TID_B = 89;
ThreadStateCoordinator::ThreadIDSet pending_stop_tids { PENDING_TID_A, PENDING_TID_B };
bool call_after_fired = false;
lldb::tid_t reported_firing_tid = 0;
int request_thread_stop_calls = 0;
ThreadStateCoordinator::ThreadIDSet request_thread_stop_tids;
// Notify we have a trigger that needs to be fired when all threads in the wait tid set have stopped.
coordinator.CallAfterThreadsStop (TRIGGERING_TID,
pending_stop_tids,
[&](lldb::tid_t tid) {
++request_thread_stop_calls;
request_thread_stop_tids.insert (tid);
},
[&](lldb::tid_t tid) {
call_after_fired = true;
reported_firing_tid = tid;
});
// Neither trigger should have gone off yet.
ASSERT_EQ (false, call_after_fired);
ASSERT_EQ (0, request_thread_stop_calls);
// Execute CallAfterThreadsStop.
ASSERT_EQ (true, coordinator.ProcessNextEvent ());
// Both TID A and TID B should have had stop requests made.
ASSERT_EQ (2, request_thread_stop_calls);
ASSERT_EQ (1, request_thread_stop_tids.count (PENDING_TID_A));
// But we still shouldn't have the deferred signal call go off yet.
ASSERT_EQ (false, call_after_fired);
// Report thread A stopped.
coordinator.NotifyThreadStop (PENDING_TID_A);
ASSERT_EQ (true, coordinator.ProcessNextEvent ());
ASSERT_EQ (false, call_after_fired);
// Now report thread A is resuming. Ensure the resume is called.
bool resume_called = false;
coordinator.RequestThreadResume (PENDING_TID_A, [&](lldb::tid_t tid) { resume_called = true; } );
ASSERT_EQ (false, resume_called);
ASSERT_EQ (true, coordinator.ProcessNextEvent ());
ASSERT_EQ (true, resume_called);
// Report thread B stopped.
coordinator.NotifyThreadStop (PENDING_TID_B);
ASSERT_EQ (false, call_after_fired);
ASSERT_EQ (true, coordinator.ProcessNextEvent ());
// After notifying thread b stopped, we now have thread a resumed but thread b stopped.
// However, since thread a had stopped, we now have had both requirements stopped at some point.
// For now we'll expect this will fire the pending deferred stop notification.
ASSERT_EQ (true, call_after_fired);
}

View File

@ -68,6 +68,7 @@ public:
EventBase (), EventBase (),
m_triggering_tid (triggering_tid), m_triggering_tid (triggering_tid),
m_wait_for_stop_tids (wait_for_stop_tids), m_wait_for_stop_tids (wait_for_stop_tids),
m_original_wait_for_stop_tids (wait_for_stop_tids),
m_request_thread_stop_func (request_thread_stop_func), m_request_thread_stop_func (request_thread_stop_func),
m_call_after_func (call_after_func) m_call_after_func (call_after_func)
{ {
@ -84,6 +85,19 @@ public:
return m_wait_for_stop_tids; return m_wait_for_stop_tids;
} }
const ThreadIDSet &
GetRemainingWaitTIDs () const
{
return m_wait_for_stop_tids;
}
const ThreadIDSet &
GetInitialWaitTIDs () const
{
return m_original_wait_for_stop_tids;
}
bool bool
ProcessEvent(ThreadStateCoordinator &coordinator) override ProcessEvent(ThreadStateCoordinator &coordinator) override
{ {
@ -167,6 +181,7 @@ private:
const lldb::tid_t m_triggering_tid; const lldb::tid_t m_triggering_tid;
ThreadIDSet m_wait_for_stop_tids; ThreadIDSet m_wait_for_stop_tids;
const ThreadIDSet m_original_wait_for_stop_tids;
ThreadIDFunc m_request_thread_stop_func; ThreadIDFunc m_request_thread_stop_func;
ThreadIDFunc m_call_after_func; ThreadIDFunc m_call_after_func;
}; };
@ -288,9 +303,36 @@ public:
return true; return true;
} }
// Before we do the resume below, first check if we have a pending
// stop notification this is currently or was previously waiting for
// this thread to stop. This is potentially a buggy situation since
// we're ostensibly waiting for threads to stop before we send out the
// pending notification, and here we are resuming one before we send
// out the pending stop notification.
const EventCallAfterThreadsStop *const pending_stop_notification = coordinator.GetPendingThreadStopNotification ();
if (pending_stop_notification)
{
if (pending_stop_notification->GetRemainingWaitTIDs ().count (m_tid) > 0)
{
coordinator.Log ("EventRequestResume::%s about to resume tid %" PRIu64 " per explicit request but we have a pending stop notification (tid %" PRIu64 ") that is actively waiting for this thread to stop. Valid sequence of events?", __FUNCTION__, m_tid, pending_stop_notification->GetTriggeringTID ());
}
else if (pending_stop_notification->GetInitialWaitTIDs ().count (m_tid) > 0)
{
coordinator.Log ("EventRequestResume::%s about to resume tid %" PRIu64 " per explicit request but we have a pending stop notification (tid %" PRIu64 ") that hasn't fired yet and this is one of the threads we had been waiting on (and already marked satisfied for this tid). Valid sequence of events?", __FUNCTION__, m_tid, pending_stop_notification->GetTriggeringTID ());
for (auto tid : pending_stop_notification->GetRemainingWaitTIDs ())
{
coordinator.Log ("EventRequestResume::%s tid %" PRIu64 " deferred stop notification still waiting on tid %" PRIu64,
__FUNCTION__,
pending_stop_notification->GetTriggeringTID (),
tid);
}
}
}
// Request a resume. We expect this to be synchronous and the system // Request a resume. We expect this to be synchronous and the system
// to reflect it is running after this completes. // to reflect it is running after this completes.
m_request_thread_resume_func (m_tid); m_request_thread_resume_func (m_tid);
return true; return true;
} }
@ -343,10 +385,9 @@ ThreadStateCoordinator::SetPendingNotification (const EventBaseSP &event_sp)
const EventCallAfterThreadsStop *new_call_after_event = static_cast<EventCallAfterThreadsStop*> (event_sp.get ()); const EventCallAfterThreadsStop *new_call_after_event = static_cast<EventCallAfterThreadsStop*> (event_sp.get ());
if (m_pending_notification_sp) EventCallAfterThreadsStop *const prev_call_after_event = GetPendingThreadStopNotification ();
if (prev_call_after_event)
{ {
const EventCallAfterThreadsStop *prev_call_after_event = static_cast<EventCallAfterThreadsStop*> (m_pending_notification_sp.get ());
// Yikes - we've already got a pending signal notification in progress. // Yikes - we've already got a pending signal notification in progress.
// Log this info. We lose the pending notification here. // Log this info. We lose the pending notification here.
Log ("ThreadStateCoordinator::%s dropping existing pending signal notification for tid %" PRIu64 ", to be replaced with signal for tid %" PRIu64, Log ("ThreadStateCoordinator::%s dropping existing pending signal notification for tid %" PRIu64 ", to be replaced with signal for tid %" PRIu64,
@ -377,9 +418,9 @@ ThreadStateCoordinator::ThreadDidStop (lldb::tid_t tid)
m_tid_stop_map[tid] = true; m_tid_stop_map[tid] = true;
// If we have a pending notification, remove this from the set. // If we have a pending notification, remove this from the set.
if (m_pending_notification_sp) EventCallAfterThreadsStop *const call_after_event = GetPendingThreadStopNotification ();
if (call_after_event)
{ {
EventCallAfterThreadsStop *const call_after_event = static_cast<EventCallAfterThreadsStop*> (m_pending_notification_sp.get ());
const bool pending_stops_remain = call_after_event->RemoveThreadStopRequirementAndMaybeSignal (tid); const bool pending_stops_remain = call_after_event->RemoveThreadStopRequirementAndMaybeSignal (tid);
if (!pending_stops_remain) if (!pending_stops_remain)
{ {
@ -396,11 +437,11 @@ ThreadStateCoordinator::ThreadWasCreated (lldb::tid_t tid)
// We assume a created thread is not stopped. // We assume a created thread is not stopped.
m_tid_stop_map[tid] = false; m_tid_stop_map[tid] = false;
if (m_pending_notification_sp) EventCallAfterThreadsStop *const call_after_event = GetPendingThreadStopNotification ();
if (call_after_event)
{ {
// Tell the pending notification that we need to wait // Tell the pending notification that we need to wait
// for this new thread to stop. // for this new thread to stop.
EventCallAfterThreadsStop *const call_after_event = static_cast<EventCallAfterThreadsStop*> (m_pending_notification_sp.get ());
call_after_event->AddThreadStopRequirement (tid); call_after_event->AddThreadStopRequirement (tid);
} }
} }
@ -414,9 +455,9 @@ ThreadStateCoordinator::ThreadDidDie (lldb::tid_t tid)
m_tid_stop_map.erase (tid); m_tid_stop_map.erase (tid);
// If we have a pending notification, remove this from the set. // If we have a pending notification, remove this from the set.
if (m_pending_notification_sp) EventCallAfterThreadsStop *const call_after_event = GetPendingThreadStopNotification ();
if (call_after_event)
{ {
EventCallAfterThreadsStop *const call_after_event = static_cast<EventCallAfterThreadsStop*> (m_pending_notification_sp.get ());
const bool pending_stops_remain = call_after_event->RemoveThreadStopRequirementAndMaybeSignal (tid); const bool pending_stops_remain = call_after_event->RemoveThreadStopRequirementAndMaybeSignal (tid);
if (!pending_stops_remain) if (!pending_stops_remain)
{ {
@ -505,3 +546,9 @@ ThreadStateCoordinator::ProcessNextEvent ()
{ {
return DequeueEventWithWait()->ProcessEvent (*this); return DequeueEventWithWait()->ProcessEvent (*this);
} }
ThreadStateCoordinator::EventCallAfterThreadsStop *
ThreadStateCoordinator::GetPendingThreadStopNotification ()
{
return static_cast<EventCallAfterThreadsStop*> (m_pending_notification_sp.get ());
}

View File

@ -125,6 +125,9 @@ namespace lldb_private
void void
Log (const char *format, ...); Log (const char *format, ...);
EventCallAfterThreadsStop *
GetPendingThreadStopNotification ();
// Member variables. // Member variables.
LogFunc m_log_func; LogFunc m_log_func;