static public IisPipelineEvent GetSlowestEvent(IisRequest request)
{
IisPipelineEvent slowestPipelineEvent = new IisPipelineEvent();
double slowestTime = 0;
foreach (var pipeLineEvent in request.PipelineEvents)
{
if (pipeLineEvent.StartTimeRelativeMSec != 0 && pipeLineEvent.EndTimeRelativeMSec != 0)
{
var timeinThisEvent = pipeLineEvent.EndTimeRelativeMSec - pipeLineEvent.StartTimeRelativeMSec;
if (timeinThisEvent > slowestTime)
{
slowestTime = timeinThisEvent;
slowestPipelineEvent = pipeLineEvent;
}
}
}
// Lets check for containment to see if a child event is taking more than 50%
// of the time of this pipeline event, then we want to call that out
foreach (var pipeLineEvent in request.PipelineEvents.Where(x => (x.StartTimeRelativeMSec > slowestPipelineEvent.StartTimeRelativeMSec) && (x.EndTimeRelativeMSec <= slowestPipelineEvent.EndTimeRelativeMSec)))
{
var timeinThisEvent = pipeLineEvent.EndTimeRelativeMSec - pipeLineEvent.StartTimeRelativeMSec;
if (((timeinThisEvent / slowestTime) * 100) > 50)
{
slowestTime = timeinThisEvent;
slowestPipelineEvent = pipeLineEvent;
}
}
var timeInSlowestEvent = slowestPipelineEvent.EndTimeRelativeMSec - slowestPipelineEvent.StartTimeRelativeMSec;
var requestExecutionTime = request.EndTimeRelativeMSec - request.StartTimeRelativeMSec;
if (timeInSlowestEvent > 0 && requestExecutionTime > 500)
{
if (((timeInSlowestEvent / requestExecutionTime) * 100) < 50)
{
// So this is the scenario where the default set of events that we are tracking
// do not have any delay. Lets do our best and see if we can atleast
// populate the StartTime, EndTime
IisPipelineEvent unKnownPipeLineEvent = CheckForDelayInUnknownEvents(request, timeInSlowestEvent);
if (unKnownPipeLineEvent != null)
{
slowestPipelineEvent = unKnownPipeLineEvent;
}
}
}
return(slowestPipelineEvent);
}
static private void AddGenericStartEventToRequest(Guid contextId, TraceEvent traceEvent, Dictionary <Guid, IisRequest> iisRequests, Dictionary <Guid, int> childRequests, string pipelineEventName = "")
{
if (traceEvent.ProcessID != g_processId)
{
return;
}
ContainsIisEvents = true;
IisRequest request;
if (!iisRequests.TryGetValue(contextId, out request))
{
// so this is the case where we dont have a GENERAL_REQUEST_START
// event but we got a Module Event fired for this request
// so we do our best to create a FAKE start request event
// populating as much information as we can.
request = GenerateFakeIISRequest(contextId, null, traceEvent.TimeStampRelativeMSec);
iisRequests.Add(contextId, request);
}
var iisPipelineEvent = new IisPipelineEvent();
if (string.IsNullOrEmpty(pipelineEventName))
{
if (traceEvent.OpcodeName.ToLower().EndsWith("_start"))
{
iisPipelineEvent.Name = traceEvent.OpcodeName.Substring(0, traceEvent.OpcodeName.Length - 6);
}
// For All the AspnetReq events, they start with Enter or Begin
// Also, we want to append the AspnetReq/ in front of them so we can easily distinguish them
// as coming from ASP.NET pipeline
else if (traceEvent.OpcodeName.ToLower().EndsWith("enter") || traceEvent.OpcodeName.ToLower().EndsWith("begin"))
{
iisPipelineEvent.Name = traceEvent.EventName.Substring(0, traceEvent.EventName.Length - 5);
}
}
else
{
iisPipelineEvent.Name = pipelineEventName;
}
int childRequestRecurseLevel = GetChildEventRecurseLevel(contextId, childRequests);
iisPipelineEvent.StartTimeRelativeMSec = traceEvent.TimeStampRelativeMSec;
iisPipelineEvent.StartThreadId = traceEvent.ThreadID;
iisPipelineEvent.ProcessId = traceEvent.ProcessID;
iisPipelineEvent.ChildRequestRecurseLevel = childRequestRecurseLevel;
request.PipelineEvents.Add(iisPipelineEvent);
}
public static IisPipelineEvent CheckForDelayInUnknownEvents(IisRequest request, double timeInSlowestEvent)
{
double slowestTimeInThisEvent = 0;
int position = 0;
var pipelineEventsArray = request.PipelineEvents.ToArray();
for (int i = 0; i < pipelineEventsArray.Length - 1; i++)
{
if (pipelineEventsArray[i].EndTimeRelativeMSec != 0)
{
var timeDiff = pipelineEventsArray[i + 1].StartTimeRelativeMSec - pipelineEventsArray[i].EndTimeRelativeMSec;
if (slowestTimeInThisEvent < timeDiff)
{
slowestTimeInThisEvent = timeDiff;
position = i;
}
}
}
IisPipelineEvent unknownEvent = null;
if ((slowestTimeInThisEvent / timeInSlowestEvent) > 1.5)
{
if (position > 0)
{
unknownEvent = new IisPipelineEvent();
unknownEvent.Name = "UNKNOWN";
unknownEvent.StartThreadId = pipelineEventsArray[position].EndThreadId;
unknownEvent.EndThreadId = pipelineEventsArray[position + 1].StartThreadId;
unknownEvent.StartTimeRelativeMSec = pipelineEventsArray[position].EndTimeRelativeMSec;
unknownEvent.EndTimeRelativeMSec = pipelineEventsArray[position + 1].StartTimeRelativeMSec;
unknownEvent.ProcessId = pipelineEventsArray[position + 1].ProcessId;
}
}
return(unknownEvent);
}
