public static StackSource AnyStacks(this TraceLog eventLog, TraceProcess process = null, bool showUnknownAddresses = false, Predicate <TraceEvent> predicate = null)
{
var stackSource = new MutableTraceEventStackSource(eventLog);
var sample = new StackSourceSample(stackSource);
TraceEvents events = process == null?eventLog.Events.Filter(x => (predicate == null || predicate(x)) && x.ProcessID != 0) : process.EventsInProcess.Filter(x => predicate == null || predicate(x));
var eventSource = events.GetSource();
eventSource.AllEvents += data =>
{
var callStackIdx = data.CallStackIndex();
StackSourceCallStackIndex stackIndex = callStackIdx != CallStackIndex.Invalid ? stackSource.GetCallStack(callStackIdx, data) : StackSourceCallStackIndex.Invalid;
var eventNodeName = "Event " + data.ProviderName + "/" + data.EventName;
stackIndex = stackSource.Interner.CallStackIntern(stackSource.Interner.FrameIntern(eventNodeName), stackIndex);
sample.StackIndex = stackIndex;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
sample.Metric = 1;
stackSource.AddSample(sample);
};
eventSource.Process();
stackSource.DoneAddingSamples();
return(stackSource);
}
public static StackSource Exceptions(this TraceEvents events, TraceProcess process = null, Predicate <TraceEvent> predicate = null)
{
// optimization only
if (process != null)
{
var start = Math.Max(events.StartTimeRelativeMSec, process.StartTimeRelativeMsec);
var end = Math.Min(events.EndTimeRelativeMSec, process.EndTimeRelativeMsec);
events = events.FilterByTime(start, end);
events = events.Filter(x => (predicate == null || predicate(x)) && x.ProcessID == process.ProcessID);
}
else
{
events = events.Filter(x => (predicate == null || predicate(x)) && x.ProcessID != 0); // TODO: Is it really correc that x.ProcessID != 0 should be there? What if we want see these?
}
var eventSource = events.GetSource();
var stackSource = new MutableTraceEventStackSource(events.Log)
{
ShowUnknownAddresses = true
};
var sample = new StackSourceSample(stackSource);
eventSource.Clr.ExceptionStart += data =>
{
sample.Metric = 1;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
// Create a call stack that ends with the 'throw'
var nodeName = "Throw(" + data.ExceptionType + ") " + data.ExceptionMessage;
var nodeIndex = stackSource.Interner.FrameIntern(nodeName);
sample.StackIndex = stackSource.Interner.CallStackIntern(nodeIndex, stackSource.GetCallStack(data.CallStackIndex(), data));
stackSource.AddSample(sample);
};
eventSource.Kernel.MemoryAccessViolation += data =>
{
sample.Metric = 1;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
// Create a call stack that ends with the 'throw'
var nodeName = "AccessViolation(ADDR=" + data.VirtualAddress.ToString("x") + ")";
var nodeIndex = stackSource.Interner.FrameIntern(nodeName);
sample.StackIndex = stackSource.Interner.CallStackIntern(nodeIndex, stackSource.GetCallStack(data.CallStackIndex(), data));
stackSource.AddSample(sample);
};
eventSource.Process();
stackSource.DoneAddingSamples();
return(stackSource);
}
public static StackSource AnyStacks(this TraceEvents events, TraceProcess process = null, Predicate <TraceEvent> predicate = null)
{
// optimization only
if (process != null)
{
var start = Math.Max(events.StartTimeRelativeMSec, process.StartTimeRelativeMsec);
var end = Math.Min(events.EndTimeRelativeMSec, process.EndTimeRelativeMsec);
events = events.FilterByTime(start, end);
events = events.Filter(x => (predicate == null || predicate(x)) && x.ProcessID == process.ProcessID);
}
else
{
events = events.Filter(x => (predicate == null || predicate(x)) && x.ProcessID != 0); // TODO: Is it really correc that x.ProcessID != 0 should be there? What if we want see these?
}
var stackSource = new MutableTraceEventStackSource(events.Log)
{
ShowUnknownAddresses = true
};
var sample = new StackSourceSample(stackSource);
var eventSource = events.GetSource();
eventSource.AllEvents += data =>
{
var callStackIdx = data.CallStackIndex();
StackSourceCallStackIndex stackIndex = callStackIdx != CallStackIndex.Invalid ? stackSource.GetCallStack(callStackIdx, data) : StackSourceCallStackIndex.Invalid;
var eventNodeName = "Event " + data.ProviderName + "/" + data.EventName;
stackIndex = stackSource.Interner.CallStackIntern(stackSource.Interner.FrameIntern(eventNodeName), stackIndex);
sample.StackIndex = stackIndex;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
sample.Metric = 1;
stackSource.AddSample(sample);
};
eventSource.Process();
stackSource.DoneAddingSamples();
return(stackSource);
}
public static StackSource Exceptions(this TraceLog eventLog, TraceProcess process = null, bool showUnknownAddresses = false, Predicate <TraceEvent> predicate = null)
{
var stackSource = new MutableTraceEventStackSource(eventLog);
var sample = new StackSourceSample(stackSource);
TraceEvents events = process == null?eventLog.Events.Filter(x => (predicate == null || predicate(x)) && x.ProcessID != 0) : process.EventsInProcess.Filter(x => predicate == null || predicate(x));
var eventSource = events.GetSource();
eventSource.Clr.ExceptionStart += data =>
{
sample.Metric = 1;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
// Create a call stack that ends with the 'throw'
var nodeName = "Throw(" + data.ExceptionType + ") " + data.ExceptionMessage;
var nodeIndex = stackSource.Interner.FrameIntern(nodeName);
sample.StackIndex = stackSource.Interner.CallStackIntern(nodeIndex, stackSource.GetCallStack(data.CallStackIndex(), data));
stackSource.AddSample(sample);
};
eventSource.Kernel.MemoryAccessViolation += data =>
{
sample.Metric = 1;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
// Create a call stack that ends with the 'throw'
var nodeName = "AccessViolation(ADDR=" + data.VirtualAddress.ToString("x") + ")";
var nodeIndex = stackSource.Interner.FrameIntern(nodeName);
sample.StackIndex = stackSource.Interner.CallStackIntern(nodeIndex, stackSource.GetCallStack(data.CallStackIndex(), data));
stackSource.AddSample(sample);
};
eventSource.Process();
stackSource.DoneAddingSamples();
return(stackSource);
}
/// <summary>
/// Generate the thread time stacks, outputting to 'stackSource'.
/// </summary>
/// <param name="outputStackSource"></param>
/// <param name="traceEvents">Optional filtered trace events.</param>
public void GenerateThreadTimeStacks(MutableTraceEventStackSource outputStackSource, TraceEvents traceEvents = null)
{
m_outputStackSource = outputStackSource;
m_sample = new StackSourceSample(outputStackSource);
m_nodeNameInternTable = new Dictionary <double, StackSourceFrameIndex>(10);
m_ExternalFrameIndex = outputStackSource.Interner.FrameIntern("UNMANAGED_CODE_TIME");
m_cpuFrameIndex = outputStackSource.Interner.FrameIntern("CPU_TIME");
TraceLogEventSource eventSource = traceEvents == null?m_eventLog.Events.GetSource() :
traceEvents.GetSource();
if (GroupByStartStopActivity)
{
UseTasks = true;
}
if (UseTasks)
{
m_activityComputer = new ActivityComputer(eventSource, m_symbolReader);
m_activityComputer.AwaitUnblocks += delegate(TraceActivity activity, TraceEvent data)
{
var sample = m_sample;
sample.Metric = (float)(activity.StartTimeRelativeMSec - activity.CreationTimeRelativeMSec);
sample.TimeRelativeMSec = activity.CreationTimeRelativeMSec;
// The stack at the Unblock, is the stack at the time the task was created (when blocking started).
sample.StackIndex = m_activityComputer.GetCallStackForActivity(m_outputStackSource, activity, GetTopFramesForActivityComputerCase(data, data.Thread(), true));
StackSourceFrameIndex awaitFrame = m_outputStackSource.Interner.FrameIntern("AWAIT_TIME");
sample.StackIndex = m_outputStackSource.Interner.CallStackIntern(awaitFrame, sample.StackIndex);
m_outputStackSource.AddSample(sample);
if (m_threadToStartStopActivity != null)
{
UpdateStartStopActivityOnAwaitComplete(activity, data);
}
};
// We can provide a bit of extra value (and it is useful for debugging) if we immediately log a CPU
// sample when we schedule or start a task. That we we get the very instant it starts.
var tplProvider = new TplEtwProviderTraceEventParser(eventSource);
tplProvider.AwaitTaskContinuationScheduledSend += OnSampledProfile;
tplProvider.TaskScheduledSend += OnSampledProfile;
tplProvider.TaskExecuteStart += OnSampledProfile;
tplProvider.TaskWaitSend += OnSampledProfile;
tplProvider.TaskWaitStop += OnTaskUnblock; // Log the activity stack even if you don't have a stack.
}
if (GroupByStartStopActivity)
{
m_startStopActivities = new StartStopActivityComputer(eventSource, m_activityComputer, IgnoreApplicationInsightsRequestsWithRelatedActivityId);
// Maps thread Indexes to the start-stop activity that they are executing.
m_threadToStartStopActivity = new StartStopActivity[m_eventLog.Threads.Count];
/********* Start Unknown Async State machine for StartStop activities ******/
// The delegates below along with the AddUnkownAsyncDurationIfNeeded have one purpose:
// To inject UNKNOWN_ASYNC stacks when there is an active start-stop activity that is
// 'missing' time. It has the effect of insuring that Start-Stop tasks always have
// a metric that is not unrealistically small.
m_activityComputer.Start += delegate(TraceActivity activity, TraceEvent data)
{
StartStopActivity newStartStopActivityForThread = m_startStopActivities.GetCurrentStartStopActivity(activity.Thread, data);
UpdateThreadToWorkOnStartStopActivity(activity.Thread, newStartStopActivityForThread, data);
};
m_activityComputer.AfterStop += delegate(TraceActivity activity, TraceEvent data, TraceThread thread)
{
StartStopActivity newStartStopActivityForThread = m_startStopActivities.GetCurrentStartStopActivity(thread, data);
UpdateThreadToWorkOnStartStopActivity(thread, newStartStopActivityForThread, data);
};
m_startStopActivities.Start += delegate(StartStopActivity startStopActivity, TraceEvent data)
{
// We only care about the top-most activities since unknown async time is defined as time
// where a top most activity is running but no thread (or await time) is associated with it
// fast out otherwise (we just insure that we mark the thread as doing this activity)
if (startStopActivity.Creator != null)
{
UpdateThreadToWorkOnStartStopActivity(data.Thread(), startStopActivity, data);
return;
}
// Then we have a refcount of exactly one
Debug.Assert(m_unknownTimeStartMsec.Get((int)startStopActivity.Index) >= 0); // There was nothing running before.
m_unknownTimeStartMsec.Set((int)startStopActivity.Index, -1); // Set it so just we are running.
m_threadToStartStopActivity[(int)data.Thread().ThreadIndex] = startStopActivity;
};
m_startStopActivities.Stop += delegate(StartStopActivity startStopActivity, TraceEvent data)
{
// We only care about the top-most activities since unknown async time is defined as time
// where a top most activity is running but no thread (or await time) is associated with it
// fast out otherwise
if (startStopActivity.Creator != null)
{
return;
}
double unknownStartTime = m_unknownTimeStartMsec.Get((int)startStopActivity.Index);
if (0 < unknownStartTime)
{
AddUnkownAsyncDurationIfNeeded(startStopActivity, unknownStartTime, data);
}
// Actually emit all the async unknown events.
List <StackSourceSample> samples = m_startStopActivityToAsyncUnknownSamples.Get((int)startStopActivity.Index);
if (samples != null)
{
foreach (var sample in samples)
{
m_outputStackSource.AddSample(sample); // Adding Unknown ASync
}
m_startStopActivityToAsyncUnknownSamples.Set((int)startStopActivity.Index, null);
}
m_unknownTimeStartMsec.Set((int)startStopActivity.Index, 0);
Debug.Assert(m_threadToStartStopActivity[(int)data.Thread().ThreadIndex] == startStopActivity ||
m_threadToStartStopActivity[(int)data.Thread().ThreadIndex] == null);
m_threadToStartStopActivity[(int)data.Thread().ThreadIndex] = null;
};
}
eventSource.Clr.GCAllocationTick += OnSampledProfile;
eventSource.Clr.GCSampledObjectAllocation += OnSampledProfile;
var eventPipeTraceEventPraser = new SampleProfilerTraceEventParser(eventSource);
eventPipeTraceEventPraser.ThreadSample += OnSampledProfile;
if (IncludeEventSourceEvents)
{
eventSource.Dynamic.All += delegate(TraceEvent data)
{
// TODO decide what the correct heuristic is.
// Currently I only do this for things that might be an EventSoruce (uses the name->Guid hashing)
// Most importantly, it excludes the high volume CLR providers.
if (!TraceEventProviders.MaybeAnEventSource(data.ProviderGuid))
{
return;
}
// We don't want most of the FrameworkEventSource events either.
if (data.ProviderGuid == FrameworkEventSourceTraceEventParser.ProviderGuid)
{
if (!((TraceEventID)140 <= data.ID && data.ID <= (TraceEventID)143)) // These are the GetResponce and GetResestStream events
{
return;
}
}
// We don't care about EventPipe sample profiler events.
if (data.ProviderGuid == SampleProfilerTraceEventParser.ProviderGuid)
{
return;
}
// We don't care about the TPL provider. Too many events.
if (data.ProviderGuid == TplEtwProviderTraceEventParser.ProviderGuid)
{
return;
}
// We don't care about ManifestData events.
if (data.ID == (TraceEventID)0xFFFE)
{
return;
}
TraceThread thread = data.Thread();
if (thread == null)
{
return;
}
StackSourceCallStackIndex stackIndex = GetCallStack(data, thread);
// Tack on additional info about the event.
var fieldNames = data.PayloadNames;
for (int i = 0; i < fieldNames.Length; i++)
{
var fieldName = fieldNames[i];
var value = data.PayloadString(i);
var fieldNodeName = "EventData: " + fieldName + "=" + value;
var fieldNodeIndex = m_outputStackSource.Interner.FrameIntern(fieldNodeName);
stackIndex = m_outputStackSource.Interner.CallStackIntern(fieldNodeIndex, stackIndex);
}
stackIndex = m_outputStackSource.Interner.CallStackIntern(m_outputStackSource.Interner.FrameIntern("EventName: " + data.ProviderName + "/" + data.EventName), stackIndex);
m_threadState[(int)thread.ThreadIndex].LogThreadStack(data.TimeStampRelativeMSec, stackIndex, thread, this, false);
};
}
eventSource.Process();
m_outputStackSource.DoneAddingSamples();
m_threadState = null;
}
/// <summary>
/// If you place a file called PerfViewExtensions\PerfViewStartup next to the PerfView.exe it will
/// run execute commands in that file. If you put
///
/// DeclareFileView .etl "Demo View In Etl File" DemoDeclareFileView
///
/// It will create a child node for all .etl files called 'Demo View In Etl File' If you click
/// on this node it will execute this user command. It is passed the name of the file that was
/// opened and the name of the view that was opened (in this case 'Demo View In Etl File').
/// </summary>
public void DemoDeclareFileView(string fileName, string viewName)
{
// This demo creates a view that shows you all the START events in a stack view.
LogFile.WriteLine("************ In DemoDeclareFileView file = {0} view = {1}", fileName, viewName);
// This is an example of opening an ETL file.
ETLDataFile etlFile = OpenETLFile(fileName);
// An ETLData file is a high level construct that knows about high level 'views' of the data (CPU stacks, thread time Stacks ...)
// However if you want to create a new view, you probably want a TraceLog which is the underlying ETW data.
TraceLog traceLog = etlFile.TraceLog;
// A tracelog represent the whole ETL file (which has process, images, threads etc), we want events, and we want callbacks
// for each event which is what GetSource() does. THus we get a source (which we can add callbacks to)
var eventSource = traceLog.Events.GetSource();
// At this point create the 'output' of our routine. Our goal is to produce stacks that we will view in the
// stack viewer. Thus we create an 'empty' one fo these.
var stackSource = new MutableTraceEventStackSource(traceLog);
// A stack source is list of samples. We create a sample structure, mutate it and then call AddSample() repeatedly to add samples.
var sample = new StackSourceSample(stackSource);
// Setup the callbacks, In this case we are going to watch for stacks where GCs happen
eventSource.Clr.GCStart += delegate(GCStartTraceData data)
{
// An TraceLog should have a callstack associated with this event;
CallStackIndex callStackIdx = data.CallStackIndex();
if (callStackIdx != CallStackIndex.Invalid)
{
// Convert the TraceLog call stack to a MutableTraceEventStackSource call stack
StackSourceCallStackIndex stackCallStackIndex = stackSource.GetCallStack(callStackIdx, data);
// Add a pseudo frame on the bottom of the stack
StackSourceFrameIndex frameIdxForName = stackSource.Interner.FrameIntern("GC Gen " + data.Depth + "Reason " + data.Reason);
stackCallStackIndex = stackSource.Interner.CallStackIntern(frameIdxForName, stackCallStackIndex);
// create a sample with that stack and add it to the stack source (list of samples)
sample.Metric = 1;
sample.TimeRelativeMSec = data.TimeStampRelativeMSec;
sample.StackIndex = stackCallStackIndex;
stackSource.AddSample(sample);
}
};
// You can set up other callback for other events.
// This causes the TraceLog source to actually spin through all the events calling our callbacks as requested.
eventSource.Process();
// We are done adding sample to our stack Source, so we tell the MutableTraceEventStackSource that.
// after that is becomes viewable (and read-only).
stackSource.DoneAddingSamples();
// Take the stack source (raw data) and make it into a 'Stacks' allows you to add filtering to and send to 'OpendStackViewer'
Stacks stacksForViewer = new Stacks(stackSource, viewName, etlFile);
// Set any filtering options here.
// Now we can display the viewer.
OpenStackViewer(stacksForViewer);
}