/// <summary>
/// Called on work item begins. The activity name = providerName + activityName without 'Start' suffix.
/// It updates CurrentActivityId to track.
///
/// It returns true if the Start should be logged, otherwise (if it is illegal recursion) it return false.
///
/// The start event should use as its activity ID the CurrentActivityId AFTER calling this routine and its
/// RelatedActivityID the CurrentActivityId BEFORE calling this routine (the creator).
///
/// If activity tracing is not on, then activityId and relatedActivityId are not set
/// </summary>
public void OnStart(string providerName, string activityName, int task, ref Guid activityId, ref Guid relatedActivityId, EventActivityOptions options)
{
if (m_current == null) // We are not enabled
{
// We used to rely on the TPL provider turning us on, but that has the disadvantage that you don't get Start-Stop tracking
// until you use Tasks for the first time (which you may never do). Thus we change it to pull rather tan push for whether
// we are enabled.
if (m_checkedForEnable)
{
return;
}
m_checkedForEnable = true;
if (TplEventSource.Log.IsEnabled(EventLevel.Informational, TplEventSource.Keywords.TasksFlowActivityIds))
{
Enable();
}
if (m_current == null)
{
return;
}
}
Debug.Assert((options & EventActivityOptions.Disable) == 0);
ActivityInfo?currentActivity = m_current.Value;
string fullActivityName = NormalizeActivityName(providerName, activityName, task);
TplEventSource log = TplEventSource.Log;
if (log.Debug)
{
log.DebugFacilityMessage("OnStartEnter", fullActivityName);
log.DebugFacilityMessage("OnStartEnterActivityState", ActivityInfo.LiveActivities(currentActivity));
}
if (currentActivity != null)
{
// Stop activity tracking if we reached the maximum allowed depth
if (currentActivity.m_level >= MAX_ACTIVITY_DEPTH)
{
activityId = Guid.Empty;
relatedActivityId = Guid.Empty;
if (log.Debug)
{
log.DebugFacilityMessage("OnStartRET", "Fail");
}
return;
}
// Check for recursion, and force-stop any activities if the activity already started.
if ((options & EventActivityOptions.Recursive) == 0)
{
ActivityInfo?existingActivity = FindActiveActivity(fullActivityName, currentActivity);
if (existingActivity != null)
{
OnStop(providerName, activityName, task, ref activityId);
currentActivity = m_current.Value;
}
}
}
// Get a unique ID for this activity.
long id;
if (currentActivity == null)
{
id = Interlocked.Increment(ref m_nextId);
}
else
{
id = Interlocked.Increment(ref currentActivity.m_lastChildID);
}
// The previous ID is my 'causer' and becomes my related activity ID
relatedActivityId = EventSource.CurrentThreadActivityId;
// Add to the list of started but not stopped activities.
ActivityInfo newActivity = new ActivityInfo(fullActivityName, id, currentActivity, relatedActivityId, options);
m_current.Value = newActivity;
// Remember the current ID so we can log it
activityId = newActivity.ActivityId;
if (log.Debug)
{
log.DebugFacilityMessage("OnStartRetActivityState", ActivityInfo.LiveActivities(newActivity));
log.DebugFacilityMessage1("OnStartRet", activityId.ToString(), relatedActivityId.ToString());
}
}
/// <summary>
/// Called when a work item stops. The activity name = providerName + activityName without 'Stop' suffix.
/// It updates m_current variable to track this fact. The Stop event associated with stop should log the ActivityID associated with the event.
///
/// If activity tracing is not on, then activityId and relatedActivityId are not set
/// </summary>
public void OnStop(string providerName, string activityName, int task, ref Guid activityId)
{
if (m_current == null) // We are not enabled
{
return;
}
string fullActivityName = NormalizeActivityName(providerName, activityName, task);
TplEventSource log = TplEventSource.Log;
if (log.Debug)
{
log.DebugFacilityMessage("OnStopEnter", fullActivityName);
log.DebugFacilityMessage("OnStopEnterActivityState", ActivityInfo.LiveActivities(m_current.Value));
}
for (; ;) // This is a retry loop.
{
ActivityInfo?currentActivity = m_current.Value;
ActivityInfo?newCurrentActivity = null; // if we have seen any live activities (orphans), at he first one we have seen.
// Search to find the activity to stop in one pass. This insures that we don't let one mistake
// (stopping something that was not started) cause all active starts to be stopped
// By first finding the target start to stop we are more robust.
ActivityInfo?activityToStop = FindActiveActivity(fullActivityName, currentActivity);
// ignore stops where we can't find a start because we may have popped them previously.
if (activityToStop == null)
{
activityId = Guid.Empty;
// TODO add some logging about this. Basically could not find matching start.
if (log.Debug)
{
log.DebugFacilityMessage("OnStopRET", "Fail");
}
return;
}
activityId = activityToStop.ActivityId;
// See if there are any orphans that need to be stopped.
ActivityInfo?orphan = currentActivity;
while (orphan != activityToStop && orphan != null)
{
if (orphan.m_stopped != 0) // Skip dead activities.
{
orphan = orphan.m_creator;
continue;
}
if (orphan.CanBeOrphan())
{
// We can't pop anything after we see a valid orphan, remember this for later when we update m_current.
if (newCurrentActivity == null)
{
newCurrentActivity = orphan;
}
}
else
{
orphan.m_stopped = 1;
Debug.Assert(orphan.m_stopped != 0);
}
orphan = orphan.m_creator;
}
// try to Stop the activity atomically. Other threads may be trying to do this as well.
if (Interlocked.CompareExchange(ref activityToStop.m_stopped, 1, 0) == 0)
{
// I succeeded stopping this activity. Now we update our m_current pointer
// If I haven't yet determined the new current activity, it is my creator.
if (newCurrentActivity == null)
{
newCurrentActivity = activityToStop.m_creator;
}
m_current.Value = newCurrentActivity;
if (log.Debug)
{
log.DebugFacilityMessage("OnStopRetActivityState", ActivityInfo.LiveActivities(newCurrentActivity));
log.DebugFacilityMessage("OnStopRet", activityId.ToString());
}
return;
}
// We failed to stop it. We must have hit a race to stop it. Just start over and try again.
}
}
