private static void Main()
{
var session = new TraceEventSession("CHROMETRACE");
var source = new ETWTraceEventSource("CHROMETRACE", TraceEventSourceType.Session);
session.EnableProvider(ChromeEventParser.ProviderGuid, TraceEventLevel.Informational);
using (new ChromeEventParser(source))
{
source.Process();
}
}
internal void ProcessEtlFile()
{
// Open the file
using (var source = new ETWTraceEventSource(etlFilePath))
{
// DynamicTraceEventParser knows about EventSourceEvents
var parser = new DynamicTraceEventParser(source);
// Set up a callback for every event that prints the event
parser.All += traceEventHandler;
// Read the file, processing the callbacks.
source.Process();
// Close the file.
}
}
private void ProcessEtwSource(ISourceDataProcessor <QuicEvent, object, Guid> dataProcessor, IProgress <int> progress, CancellationToken cancellationToken)
{
using var source = new ETWTraceEventSource(filePaths);
long StartTime = 0;
source.AllEvents += (evt) =>
{
if (cancellationToken.IsCancellationRequested)
{
source.StopProcessing();
return;
}
if (info == null && evt.TimeStamp.Ticks != 0 && !IsKnownSynthEvent(evt))
{
StartTime = evt.TimeStamp.Ticks;
var firstEventNano = (evt.TimeStamp.Ticks - source.SessionStartTime.Ticks) * 100;
var lastEventNano = (source.SessionEndTime.Ticks - source.SessionStartTime.Ticks) * 100;
info = new DataSourceInfo(firstEventNano, lastEventNano, evt.TimeStamp.ToUniversalTime());
}
else if (evt.ProviderGuid == QuicEvent.ProviderGuid)
{
try
{
var quicEvent = QuicEtwEvent.TryCreate(evt, new Timestamp((evt.TimeStamp.Ticks - StartTime) * 100));
if (quicEvent != null)
{
dataProcessor.ProcessDataElement(quicEvent, this, cancellationToken);
}
}
catch
{
}
}
progress.Report((int)(evt.TimeStampRelativeMSec / source.SessionEndTimeRelativeMSec * 100));
};
source.Process();
if (info == null)
{
info = new DataSourceInfo(0, (source.SessionEndTime.Ticks - source.SessionStartTime.Ticks) * 100, source.SessionStartTime.ToUniversalTime());
}
}
/// <summary>
/// Starts a new ETW session, if it's not yet started.
/// </summary>
/// <exception cref="InvalidOperationException">The session is already started.</exception>
public void Start()
{
if (this.isStarted)
{
throw new InvalidOperationException("ETW session is already started.");
}
// Stop the native ETW session, because it can be started by the previous application instance.
this.Stop();
ManualResetEvent startedEvent = new ManualResetEvent(false);
Task.Factory.StartNew(
() =>
{
// Create a new real-time session.
this.eventSession = new TraceEventSession(this.name, fileName: null);
this.eventSession.StopOnDispose = true;
this.eventSession.BufferSizeMB = this.bufferSizeMB;
this.eventSession.EnableProvider(LazyCopyEventParser.ProviderGuid);
using (this.eventSource = new ETWTraceEventSource(this.name, TraceEventSourceType.Session))
{
LazyCopyEventParser parser = new LazyCopyEventParser(this.eventSource);
parser.FileAccessed += this.NotifyFileAccessed;
parser.FileFetched += this.NotifyFileFetched;
parser.FileNotFetched += this.NotifyFileNotFetched;
try
{
startedEvent.Set();
this.eventSource.Process();
}
finally
{
parser.FileAccessed -= this.NotifyFileAccessed;
parser.FileFetched -= this.NotifyFileFetched;
parser.FileNotFetched -= this.NotifyFileNotFetched;
}
}
},
TaskCreationOptions.LongRunning);
startedEvent.WaitOne();
this.isStarted = true;
}
public void CreateSession(string fileName = null, bool setupSource = true)
{
if (fileName == null)
{
session = new TraceEventSession(sessionName);
}
else
{
session = new TraceEventSession(sessionName, fileName);
}
if (setupSource)
{
source = session.Source;
SetupSource();
}
}
/// <summary>
/// The analyze events data.
/// </summary>
public void AnalyzeEventsData()
{
#if NET46
using (var source = new ETWTraceEventSource(this.perfDataFileName))
{
// Open the file
var parser = new DynamicTraceEventParser(source);
parser.All += delegate(TraceEvent data)
{
try
{
if (data.ProviderName.Equals("TestPlatform") && !data.EventName.Equals("ManifestData"))
{
Console.WriteLine("Received Event : {0}", data.ToString());
var key = data.ProcessID + "_" + data.ThreadID.ToString() + "_" + data.TaskName;
if (!testPlatformTaskMap.ContainsKey(key))
{
var list = new List <TestPlatformTask> {
CreateTestPlatformTask(data)
};
testPlatformTaskMap.Add(key, list);
}
else
{
if (data.Opcode == TraceEventOpcode.Start)
{
testPlatformTaskMap[key].Add(CreateTestPlatformTask(data));
}
else
{
UpdateTask(testPlatformTaskMap[key].Last(), data);
}
}
}
}
catch (Exception ex)
{
Console.WriteLine(ex.ToString());
}
};
source.Process(); // Read the file, processing the callbacks.
}
#endif
}
static void Main(string[] args)
{
// create a new real-time ETW trace session
using (var session = new TraceEventSession(SessionName)) {
// enable IIS ETW provider and set up a new trace source on it
session.EnableProvider(IISLogTraceEventParser.ProviderName, TraceEventLevel.Verbose);
using (var traceSource = new ETWTraceEventSource(SessionName, TraceEventSourceType.Session)) {
Console.WriteLine("Session started, listening for events...");
var parser = new IISLogTraceEventParser(traceSource);
parser.IISLog += OnIISRequest;
traceSource.Process();
Console.ReadLine();
traceSource.StopProcessing();
}
}
}
static void Main(string[] args)
{
// create a new real-time ETW trace session
using ( var session = new TraceEventSession(SessionName) ) {
// enable IIS ETW provider and set up a new trace source on it
session.EnableProvider(IISLogTraceEventParser.ProviderName, TraceEventLevel.Verbose);
using ( var traceSource = new ETWTraceEventSource(SessionName, TraceEventSourceType.Session) ) {
Console.WriteLine("Session started, listening for events...");
var parser = new IISLogTraceEventParser(traceSource);
parser.IISLog += OnIISRequest;
traceSource.Process();
Console.ReadLine();
traceSource.StopProcessing();
}
}
}
/// <summary>
/// Processing the data in a particular file.
/// </summary>
private static void DataProcessing(string dataFileName)
{
Out.WriteLine("Opening the output file and printing the results.");
Out.WriteLine("The list is filtered quite a bit...");
using (var source = new ETWTraceEventSource(dataFileName))
{
if (source.EventsLost != 0)
{
Out.WriteLine("WARNING: there were {0} lost events", source.EventsLost);
}
// Set up callbacks to
source.Clr.All += Print;
source.Kernel.All += Print;
// When you merge a file, some 'symbol' events are injected into the trace.
// To avoid these showing up as 'unknown' add the parser for these. This
// also shows how you hook up a TraceEventParser that is not support by
// properties on the source itself (like CLR, and kernel)
var symbolParser = new SymbolTraceEventParser(source);
symbolParser.All += Print;
#if DEBUG
// The callback above will only be called for events the parser recognizes (in the case of Kernel and CLR parsers)
// It is sometimes useful to see the other events that are not otherwise being handled. The source knows about these and you
// can ask the source to send them to you like this.
source.UnhandledEvents += delegate(TraceEvent data)
{
// To avoid 'rundown' events that happen in the beginning and end of the trace filter out things during those times
if (data.TimeStampRelativeMSec < 1000 || 9000 < data.TimeStampRelativeMSec)
{
return;
}
Out.WriteLine("GOT UNHANDLED EVENT: " + data.Dump());
};
#endif
// go into a loop processing events can calling the callbacks. This will return when the all the events
// In the file are processed, or the StopProcessing() call is made.
source.Process();
Out.WriteLine("Done Processing.");
}
}
public void Writing_Message_To_Etw() {
var fpath = Path.Combine(Path.GetTempPath(), "_etwnlogtest.etl");
using (var session = new TraceEventSession("SimpleMonitorSession", fpath)) {
//var eventSourceGuid = TraceEventProviders.GetEventSourceGuidFromName("MyEventSource");
var eventSourceGuid = TraceEventProviders.GetEventSourceGuidFromName("LowLevelDesign-NLogEtwSource");
session.EnableProvider(eventSourceGuid);
// send events to session
var logger = LogManager.GetLogger("A");
logger.Debug("test-debug");
logger.Info("test-info");
logger.Warn("test-warn");
logger.Error("test-error");
logger.Fatal("test-fatal");
Thread.Sleep(5000);
}
var collectedEvents = new List<ExtendedEtwEvent>(5);
using (var source = new ETWTraceEventSource(fpath)) {
var parser = new DynamicTraceEventParser(source);
parser.All += delegate(TraceEvent data) {
collectedEvents.Add(new ExtendedEtwEvent {
EventId = (int)data.ID,
Level = data.Level,
LoggerName = (String)data.PayloadByName("LoggerName"),
Message = (String)data.PayloadByName("Message")
});
};
source.Process();
}
File.Delete(fpath);
// assert collected events
var expectedEvents = new ExtendedEtwEvent[] {
new ExtendedEtwEvent { EventId = 1, LoggerName = "A", Level = TraceEventLevel.Verbose, Message = "DEBUG|A|test-debug" },
new ExtendedEtwEvent { EventId = 2, LoggerName = "A", Level = TraceEventLevel.Informational, Message = "INFO|A|test-info" },
new ExtendedEtwEvent { EventId = 3, LoggerName = "A", Level = TraceEventLevel.Warning, Message = "WARN|A|test-warn" },
new ExtendedEtwEvent { EventId = 4, LoggerName = "A", Level = TraceEventLevel.Error, Message = "ERROR|A|test-error" },
new ExtendedEtwEvent { EventId = 5, LoggerName = "A", Level = TraceEventLevel.Critical, Message = "FATAL|A|test-fatal" }
};
Assert.Equal(collectedEvents, expectedEvents);
}
private bool VerifyManifestAndRemoveFile(string fileName)
{
Assert.True(File.Exists(fileName));
ETWTraceEventSource source = new ETWTraceEventSource(fileName);
var sawManifestData = false;
source.Dynamic.All += (eventData) =>
{
if (eventData.ProviderName.Equals("SimpleEventSource") && eventData.EventName.Equals("ManifestData"))
{
sawManifestData = true;
}
};
source.Process();
//File.Delete(fileName);
return(sawManifestData);
}
public void Start()
{
if (this.session != null)
{
throw new InvalidOperationException("The session is already started.");
}
CloseExistingSession(this.name);
this.session = new TraceEventSession(this.name, null);
this.session.StopOnDispose = true;
this.session.EnableProvider(KernelProcessProviderId, TraceEventLevel.Informational, ulong.MaxValue, 0x10);
this.eventSource = new ETWTraceEventSource(this.name, TraceEventSourceType.Session);
this.parser = new RegisteredTraceEventParser(this.eventSource);
this.parser.All += this.OnEventRead;
// Process() blocks until the session is shut down, so we'll run this on another thread.
this.cts = new CancellationTokenSource();
this.processTask = Task.Factory.StartNew(() => this.eventSource.Process(), TaskCreationOptions.LongRunning);
}
private static void Main(string[] args)
{
string sessionName = "mySession";
using (MyEventSource source = new MyEventSource())
using (TraceEventSession session = new TraceEventSession(sessionName, null)) // the null second parameter means 'real time session'
using (ETWTraceEventSource eventSource = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session))
{
DynamicTraceEventParser parser = new DynamicTraceEventParser(eventSource);
parser.All += delegate(TraceEvent data)
{
Console.WriteLine("Event name:{0}. Payload:{1}.", data.EventName, data.PayloadValue(0));
};
session.EnableProvider(source.Guid);
source.String("Hello world");
source.Int(123);
eventSource.Process();
}
}
/// <summary>
/// Start listening and processing events.
/// </summary>
internal void StartProcessing()
{
StopProcessing();
stopProcessing = false;
// Create new trace session.
traceEventSession = new TraceEventSession(TraceEventSessionName, null);
traceEventSession.StopOnDispose = true;
// Open a ETW event source for processing. Provide the name of real time sessing to open.
traceEventSource = new ETWTraceEventSource(TraceEventSessionName, TraceEventSourceType.Session);
DynamicTraceEventParser parser = new DynamicTraceEventParser(traceEventSource);
parser.All += (traceEvent) =>
{
if (stopProcessing)
{
traceEventSource.StopProcessing();
}
traceEventHandler(traceEvent);
};
// Add an additional provider represented by providerGuid
traceEventSession.EnableProvider(providerGuid);
// Enqueue on the thread pool's global queue.
// Processing never completes by itself, but only is Close() method is called.
eventProcessingTask = Task.Factory.StartNew(() =>
{
try
{
traceEventSource.Process();
}
catch (NullReferenceException)
{
// There is a bug in ETWTraceEventSource it can throw NullReferenceException exception!
}
});
}
private static void Main(string[] args)
{
string sessionName = "mySession";
using (MyEventSource source = new MyEventSource())
using (TraceEventSession session = new TraceEventSession(sessionName, null)) // the null second parameter means 'real time session'
using (ETWTraceEventSource eventSource = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session))
{
DynamicTraceEventParser parser = new DynamicTraceEventParser(eventSource);
parser.All += delegate(TraceEvent data)
{
Console.WriteLine("Event name:{0}. Payload:{1}.", data.EventName, data.PayloadValue(0));
};
session.EnableProvider(source.Guid);
source.String("Hello world");
source.Int(123);
eventSource.Process();
}
}
private void CreateEventSourceOnBufferFile()
{
String oldFile = SwitchBufferFiles();
Trace.WriteLine(String.Format("Starting processing on: {0}", oldFile));
this.eventSource = new ETWTraceEventSource(
oldFile, TraceEventSourceType.FileOnly
);
var sortedProvs = eventProviders.OrderBy(x => x.IsKernelProvider ? 0 : 1);
foreach (var provider in sortedProvs)
{
provider.RegisterParser(this.eventSource);
}
this.observableStream = JoinStreams(sortedProvs);
this.sourceProcessor.Start(this.observableStream);
new Task(Process).Start();
}
private static EtwPerformanceMetricEvaluationContext GetEtwReader(
string fileName,
string sessionName,
IEnumerable <PerformanceTestMessage> performanceTestMessages)
{
using (var source = new ETWTraceEventSource(fileName))
{
if (source.EventsLost > 0)
{
throw new Exception($"Events were lost in trace '{fileName}'");
}
using (var context = new EtwPerformanceMetricEvaluationContext(
fileName, source, performanceTestMessages, sessionName))
{
source.Process();
return(context);
}
}
}
public void Start()
{
using (var session = new TraceEventSession("netric"))
{
session.EnableProvider(NetricInterceptWebRequestTraceEventParser.ProviderName);
session.EnableProvider(NetricInterceptClrTraceEventParser.ProviderName);
using (var source = new ETWTraceEventSource("netric", TraceEventSourceType.Session))
{
var requestTraceEventParser = new NetricInterceptWebRequestTraceEventParser(source);
requestTraceEventParser.OnBegin+= x => _receiverActor.Tell(new EtwEventProcessingActor.RequestBegin(x));
requestTraceEventParser.OnEnd += x => _receiverActor.Tell(new EtwEventProcessingActor.RequestEnd(x));
var clrTraceEventParser = new NetricInterceptClrTraceEventParser(source);
clrTraceEventParser.OnEnter += x => _receiverActor.Tell(new EtwEventProcessingActor.MethodEnter(x));
clrTraceEventParser.OnLeave += x => _receiverActor.Tell(new EtwEventProcessingActor.MethodLeave(x));
source.Process();
}
}
}
public IPerformanceMetricReader GetReader()
{
using (var source = new ETWTraceEventSource(_etlPath))
{
if (source.EventsLost > 0)
throw new Exception($"Events were lost in trace '{_etlPath}'");
var evaluationContext = new EtwPerformanceMetricEvaluationContext(_etlPath, source, _tests, _project.RunId);
try
{
source.Process();
return evaluationContext;
}
catch
{
evaluationContext.Dispose();
throw;
}
}
}
public void Stop()
{
using (var rundownSession = new TraceEventSession(sessionName + "Rundown", "data.clrRundown.etl"))
{
rundownSession.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Verbose,
(ulong)ClrRundownTraceEventParser.Keywords.Default);
// Poll until 2 second goes by without growth.
for (var prevLength = new FileInfo("data.clrRundown.etl").Length;;)
{
Thread.Sleep(2000);
var newLength = new FileInfo("data.clrRundown.etl").Length;
if (newLength == prevLength)
{
break;
}
prevLength = newLength;
}
}
// TODO: Currenty not aware of any more sophisticated control, when hosting sub-process it will wait for timeout without new events after sub-process ends
//Thread.Sleep(4000);
stopped = true;
session?.Dispose();
kernelSession?.Dispose();
TraceEventSession.MergeInPlace("data.etl", TextWriter.Null);
//var traceLog = TraceLog.OpenOrConvert("data.etl");
//var simpleTraceLogProcess = traceLog.Processes.LastProcessWithID(Process.GetCurrentProcess().Id);
//foreach (var data in simpleTraceLogProcess.EventsInProcess)
//{
//}
using (var source = new ETWTraceEventSource("data.etl"))
{
source.Clr.GCHeapStats += ClrOnGcHeapStats;
source.Clr.GCStart += ClrOnGcStart;
source.Clr.GCStop += ClrOnGcStop;
source.Clr.GCGenerationRange += ClrOnGcGenerationRange;
source.Process();
}
}
public void Writing_Message_To_Etw()
{
var resetEvent = new ManualResetEvent(false);
var fpath = Path.Combine(Path.GetTempPath(), "_etwnlogtest.etl");
using (var session = new TraceEventSession("SimpleMonitorSession", fpath)) {
session.EnableProvider(providerId);
// send events to session
var logger = LogManager.GetLogger("A");
logger.Debug("test-debug");
logger.Info("test-info");
logger.Warn("test-warn");
logger.Error("test-error");
logger.Fatal("test-fatal");
}
var collectedEvents = new List<SimpleEtwEvent>(5);
using (var source = new ETWTraceEventSource(fpath)) {
source.UnhandledEvents += delegate(TraceEvent data) {
collectedEvents.Add(new SimpleEtwEvent { Level = data.Level, Message = data.FormattedMessage });
if (collectedEvents.Count == 5)
{
resetEvent.Set();
}
};
source.Process();
}
File.Delete(fpath);
// assert collected events
var expectedEvents = new SimpleEtwEvent[] {
new SimpleEtwEvent { Level = TraceEventLevel.Verbose, Message = "DEBUG|A|test-debug" },
new SimpleEtwEvent { Level = TraceEventLevel.Informational, Message = "INFO|A|test-info" },
new SimpleEtwEvent { Level = TraceEventLevel.Warning, Message = "WARN|A|test-warn" },
new SimpleEtwEvent { Level = TraceEventLevel.Error, Message = "ERROR|A|test-error" },
new SimpleEtwEvent { Level = TraceEventLevel.Critical, Message = "FATAL|A|test-fatal" }
};
resetEvent.WaitOne(20000);
Assert.Equal(expectedEvents.Length, collectedEvents.Count);
Assert.Equal(expectedEvents, collectedEvents);
}
/// <summary>
/// Generate the PerfEventsData from the info provided to the ctor.
/// </summary>
/// <returns>A new instance of the AggregateEventsData class.</returns>
public AggregateEventsData Generate()
{
using (var eventSource = new ETWTraceEventSource(m_etlFile))
{
if (eventSource.EventsLost > 0)
Console.WriteLine("WARNING: {0} events were lost during capture.", eventSource.EventsLost);
m_aed = new AggregateEventsData(m_testName, Platform.Windows, eventSource.PointerSize == 8 ? Architecture.Amd64 : Architecture.X86);
ParseClrTraceEvents(eventSource);
ParseKernelTraceEvents(eventSource);
// process the stream of events
eventSource.Process();
}
if (!m_processFound)
throw new ArgumentException(string.Format("No data was found for process named {0}. Please ensure the name of the process is correct.", m_process));
return m_aed;
}
/// <summary>
/// Creates the .NET CAP Report
/// </summary>
/// <param name="etlFile"></param>
/// <returns></returns>
public static ClrCap.CAPAnalysis CreateGCCap(string etlFile)
{
using (ETWTraceEventSource source = new ETWTraceEventSource(etlFile, TraceEventSourceType.MergeAll))
{
using (ETWTraceEventModelSource model = new ETWTraceEventModelSource(source))
{
model.DisableAll().EnableGC();
ClrCap.CAPAnalysis report = new ClrCap.CAPAnalysis();
SetupCapCollectors(model.Source, report);
model.Process();
UpdateCommonInfo(etlFile, model.Source, report);
// generate the report
ClrCap.CAP.GenerateGCCAPReport(model.Processes, report);
return(report);
}
}
}
private void SetupListeners(ETWTraceEventSource source)
{
// register for high and low keyword
// if both are set, each allocation will trigger an event (beware performance issues...)
source.Clr.GCSampledObjectAllocation += OnSampleObjectAllocation;
// required to receive the mapping between type ID (received in GCSampledObjectAllocation)
// and their name (received in TypeBulkType)
source.Clr.TypeBulkType += OnTypeBulkType;
// messages to get callstacks
// the correlation seems to be as "simple" as taking the last event on the same thread
source.Clr.ClrStackWalk += OnClrStackWalk;
// needed to get JITed method details
source.Clr.MethodLoadVerbose += OnMethodDetails;
source.Clr.MethodDCStartVerboseV2 += OnMethodDetails;
// get notified when a module is load to map the corresponding symbols
source.Kernel.ImageLoad += OnImageLoad;
}
/// <summary>
/// Enable the Kernel provider and listening to the provider for ProcessStartGroup event,
/// which is published by the TraceEvent library. ProcessStartGroup events are used to
/// calculate the ProcessID->ProcessName mapping, which will be used in the UI displaying.
/// However, this mechanism is not supported on XP/2003, and we cannot receive ProcessStartGroup
/// events on XP/2003.
/// </summary>
public void EnableKernelSession()
{
if (m_kernelProcessTraceThread == null)
{
m_kernelSession = new TraceEventSession(KernelTraceEventParser.KernelSessionName, null);
try
{
m_kernelSession.EnableKernelProvider(KernelTraceEventParser.Keywords.Process);
}
catch (UnauthorizedAccessException)
{
MessageBox.Show(Resource.ResourceManager.GetString("Err_UnauthorizedAccess"));
Environment.Exit(0);
}
m_kernelSource = new ETWTraceEventSource(KernelTraceEventParser.KernelSessionName, TraceEventSourceType.Session);
m_kernelSource.Kernel.ProcessStartGroup += AcceptKernelProcessStartEvent;
m_kernelProcessTraceThread = new Thread(KernelProcessTraceMethod);
m_kernelProcessTraceThread.Name = "KernelProcessTrace";
m_kernelProcessTraceThread.Start();
}
}
public IterationDataSource(string rootDir, string iterFolder)
{
string resultFile = Path.Combine(iterFolder, Constants.ResultJsonName);
Debug.Assert(File.Exists(resultFile));
IterationResult iter = JsonConvert.DeserializeObject <IterationResult>(File.ReadAllText(resultFile));
string traceFile = Path.Combine(rootDir, iter.TracePathLocation);
Debug.Assert(File.Exists(traceFile));
// we have to unzip the trace that PerfView collected. Normally
// PerfView does it, but since we're not using PerfView to read
// the data we collected we're stuck doing it ourselves.
string unzippedEtlPath = Path.Combine(iterFolder, Constants.UnzippedTraceName);
Logger.LogVerbose($"Unzipping trace {traceFile}");
ZipFile.ExtractToDirectory(traceFile, unzippedEtlPath);
// traceFile has a .etl.zip extensions, and we're looking for a file with a .etl
// extension in the unzipped ETL path.
string strippedFilename = Path.GetFileNameWithoutExtension(traceFile);
Logger.LogVerbose("Parsing ETW events");
var source = new ETWTraceEventSource(Path.Combine(unzippedEtlPath, strippedFilename));
m_source = source;
source.NeedLoadedDotNetRuntimes();
Logger.LogVerbose("Calculating GC stats");
source.Process();
Trace = source.Processes()
// TODO(segilles) this isn't quite right, it's possible (but HIGHLY unlikely)
// that we could collide pids.
.First(t => t.ProcessID == iter.Pid)
.LoadedDotNetRuntime();
TraceLocation = iter.TracePathLocation;
DurationMsec = iter.DurationMsec;
ExitCode = iter.ExitCode;
}
public IPerformanceMetricReader GetReader()
{
using (var source = new ETWTraceEventSource(_etlPath))
{
if (source.EventsLost > 0)
{
throw new Exception($"Events were lost in trace '{_etlPath}'");
}
var evaluationContext = new EtwPerformanceMetricEvaluationContext(_etlPath, source, _tests, _project.RunId);
try
{
source.Process();
return(evaluationContext);
}
catch
{
evaluationContext.Dispose();
throw;
}
}
}
public override void Dispose()
{
_session.Flush();
Thread.Sleep(1010); // Let it drain.
_session.Dispose(); // This also will kill the real time thread
if (_dataFileName != null)
{
using (var traceEventSource = new ETWTraceEventSource(_dataFileName))
{
Debug.WriteLine("Processing data file " + Path.GetFullPath(_dataFileName));
// Parse all the events as as best we can, and also send unhandled events there as well.
traceEventSource.Registered.All += OnEventHelper;
traceEventSource.Dynamic.All += OnEventHelper;
traceEventSource.UnhandledEvents += OnEventHelper;
// Process all the events in the file.
traceEventSource.Process();
Debug.WriteLine("Done processing data file " + Path.GetFullPath(_dataFileName));
}
}
}
private static void CallThis()
{
var sessionName = "ProcessMonitorSession";
using (var session = new TraceEventSession(sessionName, null))
{
session.StopOnDispose = true;
using (var source = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session))
{
var registeredParser = new RegisteredTraceEventParser(source);
registeredParser.All += delegate(TraceEvent data)
{
var taskName = data.TaskName;
if (taskName == "ProcessStart" || taskName == "ProcessStop")
{
string exe = (string)data.PayloadByName("ImageName");
string exeName = Path.GetFileNameWithoutExtension(exe);
int processId = (int)data.PayloadByName("ProcessID");
if (taskName == "ProcessStart")
{
int parentProcessId = (int)data.PayloadByName("ParentProcessID");
// log:
//string.Format("{0:HH:mm:ss.fff}: {1,-12}: {2} ID: {3} ParentID: {4}", data.TimeStamp, taskName, exeName, processId, parentProcessId);
}
else
{
int exitCode = (int)data.PayloadByName("ExitCode");
long cpuCycle = (long)data.PayloadByName("CPUCycleCount");
// log:
//string.Format("{0:HH:mm:ss.fff}: {1,-12}: {2} ID: {3} EXIT: {4} CPU Cycles: {5:n0}", data.TimeStamp, taskName, exeName, processId, exitCode, cpuCycle);
}
}
};
//var processProviderGuid = TraceEventSession.
}
}
}
private static void WorkerTraceEvents(object sender, DoWorkEventArgs e)
{
try
{
if (TraceEventSession.IsElevated() != true)
{
throw new InvalidOperationException(
"Collecting ETW trace events requires administrative privileges.");
}
if (TraceEventSession.GetActiveSessionNames().Contains(SessionName))
{
Debug.WriteLine(
$"The session name '{SessionName}' is already in use, stopping existing and restart a new one.");
TraceEventSession.GetActiveSession(SessionName).Stop(true);
}
// An End-To-End ETW Tracing Example: EventSource and TraceEvent
// https://blogs.msdn.microsoft.com/vancem/2012/12/20/an-end-to-end-etw-tracing-example-eventsource-and-traceevent/
using (var traceEventSession = new TraceEventSession(SessionName))
{
traceEventSession.StopOnDispose = true;
using (var traceEventSource = new ETWTraceEventSource(SessionName, TraceEventSourceType.Session))
{
traceEventSession.EnableProvider(OmaDmClient);
traceEventSession.EnableProvider(OmaDmClientProvider);
new RegisteredTraceEventParser(traceEventSource).All += (data =>
(sender as BackgroundWorker)?.ReportProgress(0, data.Clone()));
traceEventSource.Process();
}
}
}
catch (Exception ex)
{
Debug.WriteLine($"Exception: {ex}");
}
}
public void Dispose()
{
if (!this.disposed)
{
this.disposing = true;
if (this.eventsLost > 0)
{
this.logger.TraceEventServiceProcessEventsLost(this.sessionName, this.eventsLost);
}
// By disposing source we force this.source.Process() to exit and end workerTask
// Note that source reference is not released rigth after Dispose() to avoid 'CallbackOnCollectedDelegate'exception
// that might be thrown before Process() ends.
this.source.Dispose();
this.workerTask.Wait();
this.session.Dispose();
this.session = null;
this.source = null;
this.disposed = true;
}
}
public void Dispose()
{
if (!this.disposed)
{
this.disposing = true;
if (this.eventsLost > 0)
{
this.logger.TraceEventServiceProcessEventsLost(this.sessionName, this.eventsLost);
}
// By disposing source we force this.source.Process() to exit and end workerTask
// Note that source reference is not released rigth after Dispose() to avoid 'CallbackOnCollectedDelegate'exception
// that might be thrown before Process() ends.
this.source.Dispose();
this.workerTask.Wait();
this.session.Dispose();
this.session = null;
this.source = null;
this.disposed = true;
}
}
private void StartListening()
{
this.eventSinkThread = new Thread(() => {
using (var session = new TraceEventSession("mo-session-01"))
{
this.session = session;
using (var source = new ETWTraceEventSource("mo-session-01", TraceEventSourceType.Session))
{
var parser = new DynamicTraceEventParser(source);
parser.All += (TraceEvent data) =>
{
var trace = TraceEventToTraceData(data);
model.AddTrace(trace);
};
session.EnableProvider(this.model.SelectedProvider);
source.Process();
}
}
});
this.eventSinkThread.Start();
}
private void Initialize()
{
this.session = TraceEventUtil.CreateSession(this.sessionName);
// Hook up the ETWTraceEventSource to the specified session
this.source = new ETWTraceEventSource(this.sessionName, TraceEventSourceType.Session);
this.manifestCache = new TraceEventManifestsCache(this.source.Dynamic);
// get any previously cached manifest and update the schema cache
this.UpdateCaches();
// hook up to all incoming events and filter out manifests
this.source.Dynamic.All += e => this.ProcessEvent(e);
// listen to new manifests
this.source.Dynamic.DynamicProviderAdded += m => this.OnManifestReceived(m);
// We collect all the manifests and save/terminate process when done
this.source.UnhandledEvents += e => this.ProcessUnhandledEvent(e);
foreach (var eventSource in this.eventSources)
{
// Bind the provider (EventSource/EventListener) with the session
TraceEventUtil.EnableProvider(
this.session,
eventSource.EventSourceId,
eventSource.Level,
eventSource.MatchAnyKeyword,
eventSource.Arguments,
eventSource.ProcessNamesToFilter);
}
// source.Process() is blocking so we need to launch it on a separate thread.
this.workerTask = Task.Factory.StartNew(() => this.source.Process(), TaskCreationOptions.LongRunning).
ContinueWith(t => this.HandleProcessTaskFault(t));
}
static int Main(string[] args)
{
if (args.Length != 2)
{
Console.WriteLine("Usage: EtlConverter.exe <input.etl> <output.log>");
return(1);
}
var inputFile = args[0];
var outputFile = args[1];
if (!File.Exists(inputFile))
{
Console.WriteLine("Input File {} does not exist", inputFile);
return(2);
}
try {
fs = new FileStream(outputFile, FileMode.Create);
} catch (Exception e) {
Console.WriteLine("Failed to open output file: {}", e);
return(3);
}
using (var source = new ETWTraceEventSource(inputFile))
{
// setup the callbacks
source.Dynamic.All += Print;
// iterate over the file, calling the callbacks.
Console.WriteLine("Processing...");
source.Process();
Console.WriteLine("Done!");
}
return(0);
}
private static void RoundTwo(string[] args)
{
using (var netPerfFile = NetPerfFile.Create(args))
{
using (var etlFile = EtlFile.Create(args))
{
Console.WriteLine("\tStart: Enable EventPipe.");
TraceControl.Enable(EventPipeGetConfig(EventPipeAndEtwEventSource.Log, EventPipeAndEtwEventSource.Keywords.EventPipeKeyword, netPerfFile.Path));
Console.WriteLine("\tEnd: Enable EventPipe.\n");
Console.WriteLine("\tStart: Enable ETW.");
TraceEventSession etwSession = EnableETW(EventPipeAndEtwEventSource.Log, EventPipeAndEtwEventSource.Keywords.EtwKeyword, etlFile.Path);
Console.WriteLine("\tEnd: Enable ETW.\n");
WriteAllEvents(EventPipeAndEtwEventSource.Log);
Console.WriteLine("\tStart: Disable EventPipe.");
TraceControl.Disable();
Console.WriteLine("\tEnd: Disable EventPipe.\n");
WriteAllEvents(EventPipeAndEtwEventSource.Log);
Console.WriteLine("\tStart: Disable ETW.");
DisableETW(etwSession);
Console.WriteLine("\tEnd: Disable ETW.\n");
Console.WriteLine("\tStart: Processing events from EventPipe file.");
EventResults eventPipeResults = new EventResults();
EventResults etwResults = new EventResults();
using (var trace = new TraceLog(TraceLog.CreateFromEventPipeDataFile(netPerfFile.Path)).Events.GetSource())
{
trace.Dynamic.All += delegate(TraceEvent data)
{
eventPipeResults.AddEvent(data);
};
trace.Process();
}
// Validate EventPipe results.
eventPipeResults.Print("EventPipe Results:");
Assert.Equal("EventPipeEvent1Count", eventPipeResults.Event1Count, 1);
Assert.Equal("EventPipeEvent2Count", eventPipeResults.Event2Count, 0);
Assert.Equal("EventPipeEvent3Count", eventPipeResults.Event3Count, 1);
Console.WriteLine("\tEnd: Processing events from EventPipe file.\n");
Console.WriteLine("\tStart: Processing events from ETW file.");
using (var trace = new ETWTraceEventSource(etlFile.Path))
{
trace.Dynamic.All += delegate(TraceEvent data)
{
etwResults.AddEvent(data);
};
trace.Process();
}
// Validate ETW results.
etwResults.Print("ETW Results:");
Assert.Equal("EventPipeEvent1Count", etwResults.Event1Count, 0);
Assert.Equal("EventPipeEvent2Count", etwResults.Event2Count, 2);
Assert.Equal("EventPipeEvent3Count", etwResults.Event3Count, 2);
Console.WriteLine("\tEnd: Processing events from ETW file.");
}
}
}
public static bool TraceETWTraceEventSource
(
string providerName
, string tracedFileName
, string[] traceEvents = null
, Action
<
long
, TraceEventDispatcher
, TraceEventSession
, TraceEvent
> onOneEventTracedOnceProcessAction = null
, TraceEventProviderOptions traceEventProviderOptions = null
, TraceEventSourceType traceEventSourceType = TraceEventSourceType.MergeAll
, TraceEventLevel traceEventLevel = TraceEventLevel.Always
, ulong matchKeywords = ulong.MaxValue
, bool needCountHits = false
)
{
var r = false;
if (!(TraceEventSession.IsElevated() ?? false))
{
Out.WriteLine("To turn on ETW events you need to be Administrator, please run from an Admin process.");
return r;
}
if
(
traceEvents != null
&&
traceEvents.Length > 0
&&
onOneEventTracedOnceProcessAction != null
)
{
using (var source = new ETWTraceEventSource(tracedFileName, traceEventSourceType))
{
//闭包
long sequence = 0;
RegisterCallbacks
(
providerName
, traceEvents
, source
, null
, (x, y, z) =>
{
long id = 0;
if (needCountHits)
{
id = Interlocked.Increment(ref sequence);
}
onOneEventTracedOnceProcessAction
(
id
, x
, y
, z
);
}
);
source.Process(); // call the callbacks for each event
}
}
return true;
}
private void Initialize()
{
this.session = TraceEventUtil.CreateSession(this.sessionName);
// Hook up the ETWTraceEventSource to the specified session
this.source = new ETWTraceEventSource(this.sessionName, TraceEventSourceType.Session);
this.manifestCache = new TraceEventManifestsCache(this.source.Dynamic);
// get any previously cached manifest and update the schema cache
this.UpdateCaches();
// hook up to all incoming events and filter out manifests
this.source.Dynamic.All += e => this.ProcessEvent(e);
// listen to new manifests
this.source.Dynamic.DynamicProviderAdded += m => this.OnManifestReceived(m);
// We collect all the manifests and save/terminate process when done
this.source.UnhandledEvents += e => this.ProcessUnhandledEvent(e);
foreach (var eventSource in this.eventSources)
{
// Bind the provider (EventSource/EventListener) with the session
TraceEventUtil.EnableProvider(
this.session,
eventSource.EventSourceId,
eventSource.Level,
eventSource.MatchAnyKeyword,
eventSource.Arguments,
eventSource.ProcessNamesToFilter);
}
// source.Process() is blocking so we need to launch it on a separate thread.
this.workerTask = Task.Factory.StartNew(() => this.source.Process(), TaskCreationOptions.LongRunning).
ContinueWith(t => this.HandleProcessTaskFault(t));
}
/// <summary>
/// Processing the data in a particular file.
/// </summary>
static void DataProcessing(string dataFileName)
{
Out.WriteLine("Opening the output file and printing the results.");
using (var source = new ETWTraceEventSource(dataFileName))
{
if (source.EventsLost != 0)
Out.WriteLine("WARNING: there were {0} lost events", source.EventsLost);
// Set up callbacks to
source.Clr.All += Print;
source.Kernel.All += Print;
// When you merge a file, some 'symbol' events are injected into the trace.
// To avoid these showing up as 'unknown' add the parser for these. This
// also shows how you hook up a TraceEventParser that is not support by
// properties on the source itself (like CLR, and kernel)
var symbolParser = new SymbolTraceEventParser(source);
symbolParser.All += Print;
#if DEBUG
// The callback above will only be called for events the parser recognizes (in the case of Kernel and CLR parsers)
// It is sometimes useful to see the other events that are not otherwise being handled. The source knows about these and you
// can ask the source to send them to you like this.
source.UnhandledEvents += delegate(TraceEvent data)
{
if ((int)data.ID == 0xFFFE) // The EventSource manifest events show up as unhandled, filter them out.
return;
// To avoid 'rundown' events that happen in the beginning and end of the trace filter out things during those times
if (data.TimeStampRelativeMSec < 1000 || 9000 < data.TimeStampRelativeMSec)
return;
Out.WriteLine("GOT UNHANDLED EVENT: " + data.Dump());
};
#endif
// go into a loop processing events can calling the callbacks. This will return when the all the events
// In the file are processed, or the StopProcessing() call is made.
source.Process();
Out.WriteLine("Done Processing.");
}
}
protected virtual void Dispose(bool disposing)
{
if (this.TraceEventSource != null && disposing)
{
this.StopProcessing();
this.TraceEventSource.Dispose();
this.TraceEventSource = null;
}
}
/// <summary>
/// Process the data in 'dataFileName' printing the events and doing delta computation between 'MyFirstEvent'
/// and 'MySecondEvent'.
/// </summary>
static void ProcessData(string dataFileName)
{
// prepare to read from the session, connect the ETWTraceEventSource to the file
// Notice there is no session at this point (reading and controlling are not necessarily related).
// YOu can read the file on another machine if you like.
Out.WriteLine("Opening {0} to see what data is in the file.", dataFileName);
using (var source = new ETWTraceEventSource(dataFileName))
{
if (source.EventsLost != 0)
{
Out.WriteLine("WARNING: there were {0} lost events", source.EventsLost);
}
// To demonstrate non-trivial event manipulation, we calculate the time delta between 'MyFirstEvent and 'MySecondEvent'
// firstEventTimeMSec remembers all the 'MyFirstEvent' arrival times (indexed by their ID)
var firstEventTimeMSec = new Dictionary <int, double>();
/*****************************************************************************************************/
// Hook up events. To so this first we need a 'Parser. which knows how to part the events of a particular Event Provider.
// In this case we get a DynamicTraceEventSource, which knows how to parse any EventSource provider. This parser
// is so common, that TraceEventSource as a shortcut property called 'Dynamic' that fetches this parsers.
// For debugging, and demo purposes, hook up a callback for every event that 'Dynamic' knows about (this is not EVERY
// event only those know about by DynamiceTraceEventParser). However the 'UnhandledEvents' handler below will catch
// the other ones.
source.Dynamic.All += delegate(TraceEvent data)
{
Out.WriteLine(data.PayloadByName("MyName"));
Out.WriteLine("GOT EVENT: " + data.ToString());
};
// Add logic on what to do when we get "MyFirstEvent"
source.Dynamic.AddCallbackForProviderEvent("Microsoft-Demos-SimpleMonitor", "MyFirstEvent", delegate(TraceEvent data)
{
// On First Events, simply remember the ID and time of the event
firstEventTimeMSec[(int)data.PayloadByName("MyId")] = data.TimeStampRelativeMSec;
});
// Add logic on what to do when we get "MySecondEvent"
source.Dynamic.AddCallbackForProviderEvent("Microsoft-Demos-SimpleMonitor", "MySecondEvent", delegate(TraceEvent data)
{
// On Second Events, if the ID matches, compute the delta and display it.
var myID = (int)data.PayloadByName("MyId");
double firstEventTime;
if (firstEventTimeMSec.TryGetValue(myID, out firstEventTime))
{
firstEventTimeMSec.Remove(myID); // We are done with the ID after matching it, so remove it from the table.
Out.WriteLine(" >>> Time Delta from first Event = {0:f3} MSec", data.TimeStampRelativeMSec - firstEventTime);
}
else
{
Out.WriteLine(" >>> WARNING, Found a 'SecondEvent' without a corresponding 'FirstEvent'");
}
});
// Add logic on what to do when we get "Stop"
source.Dynamic.AddCallbackForProviderEvent("Microsoft-Demos-SimpleMonitor", "MyStopEvent", delegate(TraceEvent data)
{
Out.WriteLine(" >>> Got a stop message");
// Stop processing after we we see the 'Stop' event
source.StopProcessing();
});
#if DEBUG
// There may be events that are not handled by ANY of the callbacks above. This is often a bug in your program
// (you forgot a callback). In debug we would like to see these to know that something is probably wrong.
// The 'UnhandledEvents' callback will be called whenever no other callback has handled the event. There is
// also an 'All callback on the source (not a particular parser) that will call back on EVERY event from the source
source.UnhandledEvents += delegate(TraceEvent data)
{
if ((int)data.ID != 0xFFFE) // The EventSource manifest events show up as unhandled, filter them out.
{
Out.WriteLine("GOT UNHANDLED EVENT: " + data.Dump());
}
};
#endif
// go into a loop processing events can calling the callbacks. This will return when the all the events
// In the file are processed, or the StopProcessing() call is made.
source.Process();
Out.WriteLine("Done Processing.");
}
}
/// <summary>
/// Wire up parsing of kernel event data from the specified ETWTraceEventSource.
/// </summary>
/// <param name="eventSource">The ETWTraceEventSource from which to parse the data.</param>
private void ParseKernelTraceEvents(ETWTraceEventSource eventSource)
{
if (m_kernelEvents == KernelTraceEventParser.Keywords.None)
return;
var kernelParser = new KernelTraceEventParser(eventSource);
// iterate over each set bit, wiring up a callback to parse the data
uint eventBits = (uint)m_kernelEvents;
int bitPos = 0;
while (eventBits > 0)
{
// cycle through until a set bit is found
while ((((uint)eventBits) & (uint)(1 << bitPos)) == 0)
{
++bitPos;
Debug.Assert(bitPos < 32);
}
var bitVal = (uint)(1 << bitPos);
// now strip it from eventBits and covert it to its enum value
eventBits ^= bitVal;
KernelTraceEventParser.Keywords kernelEvent = (KernelTraceEventParser.Keywords)bitVal;
if ((kernelEvent & KernelTraceEventParser.Keywords.ImageLoad) == KernelTraceEventParser.Keywords.ImageLoad)
{
var modLoads = new EventDataListString<KernelPerfEvents>(KernelPerfEvents.ModuleLoad);
modLoads.Values = new HashSet<string>(StringComparer.OrdinalIgnoreCase);
kernelParser.ImageLoad += delegate(ImageLoadTraceData data)
{
if (string.Compare(data.ProcessName, m_process, true) == 0)
{
var modName = Path.GetFileName(data.FileName);
if (!modLoads.Values.Contains(modName))
modLoads.Values.Add(modName);
m_processFound = true;
}
};
m_aed.AddData(modLoads);
}
else
{
Console.WriteLine("WARNING: Kernel event {0} NYI for reporting.", kernelEvent);
}
}
}
/// <summary>
/// Process the data in 'dataFileName' printing the events and doing delta computation between 'MyFirstEvent'
/// and 'MySecondEvent'.
/// </summary>
static void ProcessData(string dataFileName)
{
// prepare to read from the session, connect the ETWTraceEventSource to the file
// Notice there is no session at this point (reading and controlling are not necessarily related).
// YOu can read the file on another machine if you like.
Out.WriteLine("Opening {0} to see what data is in the file.", dataFileName);
using (var source = new ETWTraceEventSource(dataFileName))
{
if (source.EventsLost != 0)
Out.WriteLine("WARNING: there were {0} lost events", source.EventsLost);
// To demonstrate non-trivial event manipulation, we calculate the time delta between 'MyFirstEvent and 'MySecondEvent'
// firstEventTimeMSec remembers all the 'MyFirstEvent' arrival times (indexed by their ID)
var firstEventTimeMSec = new Dictionary<int, double>();
/*****************************************************************************************************/
// Hook up events. To so this first we need a 'Parser. which knows how to part the events of a particular Event Provider.
// In this case we get a DynamicTraceEventSource, which knows how to parse any EventSource provider. This parser
// is so common, that TraceEventSource as a shortcut property called 'Dynamic' that fetches this parsers.
// For debugging, and demo purposes, hook up a callback for every event that 'Dynamic' knows about (this is not EVERY
// event only those know about by DynamiceTraceEventParser). However the 'UnhandledEvents' handler below will catch
// the other ones.
source.Dynamic.All += delegate(TraceEvent data)
{
Out.WriteLine(data.PayloadByName("MyName"));
Out.WriteLine("GOT EVENT: " + data.ToString());
};
// Add logic on what to do when we get "MyFirstEvent"
source.Dynamic.AddCallbackForProviderEvent("Microsoft-Demos-SimpleMonitor", "MyFirstEvent", delegate(TraceEvent data)
{
// On First Events, simply remember the ID and time of the event
firstEventTimeMSec[(int)data.PayloadByName("MyId")] = data.TimeStampRelativeMSec;
});
// Add logic on what to do when we get "MySecondEvent"
source.Dynamic.AddCallbackForProviderEvent("Microsoft-Demos-SimpleMonitor", "MySecondEvent", delegate(TraceEvent data)
{
// On Second Events, if the ID matches, compute the delta and display it.
var myID = (int)data.PayloadByName("MyId");
double firstEventTime;
if (firstEventTimeMSec.TryGetValue(myID, out firstEventTime))
{
firstEventTimeMSec.Remove(myID); // We are done with the ID after matching it, so remove it from the table.
Out.WriteLine(" >>> Time Delta from first Event = {0:f3} MSec", data.TimeStampRelativeMSec - firstEventTime);
}
else
Out.WriteLine(" >>> WARNING, Found a 'SecondEvent' without a corresponding 'FirstEvent'");
});
// Add logic on what to do when we get "Stop"
source.Dynamic.AddCallbackForProviderEvent("Microsoft-Demos-SimpleMonitor", "Stop", delegate(TraceEvent data)
{
Out.WriteLine(" >>> Got a stop message");
// Stop processing after we we see the 'Stop' event
source.StopProcessing();
});
#if DEBUG
// There may be events that are not handled by ANY of the callbacks above. This is often a bug in your program
// (you forgot a callback). In debug we would like to see these to know that something is probably wrong.
// The 'UnhandledEvents' callback will be called whenever no other callback has handled the event. There is
// also an 'All callback on the source (not a particular parser) that will call back on EVERY event from the source
source.UnhandledEvents += delegate(TraceEvent data)
{
if ((int)data.ID != 0xFFFE) // The EventSource manifest events show up as unhandled, filter them out.
Out.WriteLine("GOT UNHANDLED EVENT: " + data.Dump());
};
#endif
// go into a loop processing events can calling the callbacks. This will return when the all the events
// In the file are processed, or the StopProcessing() call is made.
source.Process();
Out.WriteLine("Done Processing.");
}
}
public void OverflowCircularBufferTest()
{
string dataFileName = "OverflowData.etl";
var sessionName = Path.GetFileNameWithoutExtension(dataFileName) + "Session";
var logger = ADShutdownEventSourceTester.ADShutdownEventSource.Log;
// Normalize to a full path name.
dataFileName = Path.GetFullPath(dataFileName);
Debug.WriteLine(String.Format("Creating data file {0}", dataFileName));
TraceEventSession session = null;
using (session = new TraceEventSession(sessionName, dataFileName))
{
// Turn on the eventSource given its name.
session.CircularBufferMB = 1;
session.BufferSizeMB = 1;
session.EnableProvider(logger.Name);
Thread.Sleep(100); // Enabling is async. Wait a bit.
// Generate events for all the tests, surrounded by events that tell us we are starting a test.
var info = new AppDomainSetup { ApplicationBase = AppDomain.CurrentDomain.BaseDirectory };
var appDomain =
AppDomain.CreateDomain("TestShutdownAD", new Evidence(), info);
byte[] b = new byte[1000];
var tester = (ADShutdownEventSourceTester)appDomain
.CreateInstanceAndUnwrap(
typeof(TestShutdown).Assembly.GetName().Name,
typeof(ADShutdownEventSourceTester).FullName);
for (int i = 0; i < 1500; i++)
{
tester.LogBytes(b);
}
// Unload the AD and expect the manifest to be logged.
AppDomain.Unload(appDomain);
session.Flush();
}
// Parse ETL and search for manifest events
using (var traceEventSource = new ETWTraceEventSource(dataFileName))
{
bool hasManifestEvents = false;
Action<TraceEvent> onEvent = delegate (TraceEvent data)
{
// Check for manifest events.
if ((int)data.ID == 0xFFFE)
hasManifestEvents = true;
};
// Parse all the events as best we can, and also send unhandled events there as well.
traceEventSource.Registered.All += onEvent;
traceEventSource.Dynamic.All += onEvent;
traceEventSource.UnhandledEvent += onEvent;
traceEventSource.Process();
// Expect at least one manifest event.
Assert.True(hasManifestEvents);
}
logger.Dispose();
}
public override void Dispose()
{
_session.Flush();
Thread.Sleep(1010); // Let it drain.
_session.Dispose(); // This also will kill the real time thread
if (_dataFileName != null)
{
using (var traceEventSource = new ETWTraceEventSource(_dataFileName))
{
Debug.WriteLine("Processing data file " + Path.GetFullPath(_dataFileName));
// Parse all the events as best we can, and also send unhandled events there as well.
traceEventSource.Registered.All += OnEventHelper;
traceEventSource.Dynamic.All += OnEventHelper;
traceEventSource.UnhandledEvents += OnEventHelper;
// Process all the events in the file.
traceEventSource.Process();
Debug.WriteLine("Done processing data file " + Path.GetFullPath(_dataFileName));
}
}
}
public IEnumerable <Counter> Parse(string mergeTraceFile, string processName, IList <int> pids)
{
var results = new List <double>();
double threadTime = 0;
var threadTimes = new List <double>();
var ins = new Dictionary <int, double>();
double start = -1;
int? pid = null;
using (var source = new ETWTraceEventSource(mergeTraceFile))
{
source.Kernel.ProcessStart += evt =>
{
if (evt.ProcessName.Equals(processName, StringComparison.OrdinalIgnoreCase) && pids.Contains(evt.ProcessID))
{
if (pid.HasValue)
{
// Processes might be reentrant. For now this traces the first (outermost) process of a given name.
return;
}
pid = evt.ProcessID;
start = evt.TimeStampRelativeMSec;
}
};
source.Kernel.ThreadCSwitch += evt =>
{
if (!pid.HasValue) // we're currently in a measurement interval
{
return;
}
if (evt.NewProcessID != pid && evt.OldProcessID != pid)
{
return; // but this isn't our process
}
if (evt.OldProcessID == pid) // this is a switch out from our process
{
if (ins.TryGetValue(evt.OldThreadID, out var value)) // had we ever recorded a switch in for this thread?
{
threadTime += evt.TimeStampRelativeMSec - value;
ins.Remove(evt.OldThreadID);
}
}
else // this is a switch in to our process
{
ins[evt.NewThreadID] = evt.TimeStampRelativeMSec;
}
};
ClrPrivateTraceEventParser clrpriv = new ClrPrivateTraceEventParser(source);
clrpriv.StartupMainStart += evt =>
{
if (pid.HasValue && evt.ProcessID == pid && evt.ProcessName.Equals(processName, StringComparison.OrdinalIgnoreCase))
{
results.Add(evt.TimeStampRelativeMSec - start);
pid = null;
threadTimes.Add(threadTime);
threadTime = 0;
start = 0;
}
};
source.Process();
}
return(new[] { new Counter()
{
Name = "Time To Main", Results = results.ToArray(), TopCounter = true, DefaultCounter = true, HigherIsBetter = false, MetricName = "ms"
},
new Counter()
{
Name = "Time on Thread", Results = threadTimes.ToArray(), TopCounter = true, DefaultCounter = false, HigherIsBetter = false, MetricName = "ms"
} });
}
private void CreateEventSourceOnBufferFile()
{
String oldFile = SwitchBufferFiles();
Trace.WriteLine(String.Format("Starting processing on: {0}", oldFile));
this.eventSource = new ETWTraceEventSource(
oldFile, TraceEventSourceType.FileOnly
);
var sortedProvs = eventProviders.OrderBy(x => x.IsKernelProvider ? 0 : 1);
foreach (var provider in sortedProvs) {
provider.RegisterParser(this.eventSource);
}
this.observableStream = JoinStreams(sortedProvs);
this.sourceProcessor.Start(this.observableStream);
new Task(Process).Start();
}
public static void Main(string[] args)
{
string traceFile = args[0];
string benchmarkName = "dotnet";
int benchmarkPid = -2;
Dictionary <string, uint> allEventCounts = new Dictionary <string, uint>();
Dictionary <string, uint> eventCounts = new Dictionary <string, uint>();
Dictionary <string, uint> processCounts = new Dictionary <string, uint>();
using (var source = new ETWTraceEventSource(traceFile))
{
source.Kernel.All += delegate(TraceEvent data)
{
if (allEventCounts.ContainsKey(data.EventName))
{
allEventCounts[data.EventName]++;
}
else
{
allEventCounts[data.EventName] = 1;
}
if (data.ProcessID == benchmarkPid)
{
if (eventCounts.ContainsKey(data.EventName))
{
eventCounts[data.EventName]++;
}
else
{
eventCounts[data.EventName] = 1;
}
}
switch (data.EventName)
{
case "Process/Start":
case "Process/DCStart":
{
// Process was running when tracing started (DCStart)
// or started when tracing was running (Start)
ProcessTraceData pdata = (ProcessTraceData)data;
if (String.Equals(pdata.ProcessName, benchmarkName, StringComparison.OrdinalIgnoreCase))
{
Console.WriteLine("Found process [{0}] {1}: {2}", pdata.ProcessID, pdata.ProcessName, pdata.CommandLine);
benchmarkPid = pdata.ProcessID;
}
else
{
// Console.WriteLine("Ignoring events from process {0}", pdata.ProcessName);
}
break;
}
case "Image/DCStart":
{
ImageLoadTraceData imageLoadTraceData = (ImageLoadTraceData)data;
if (data.ProcessID == 0)
{
string fileName = imageLoadTraceData.FileName;
ulong imageBase = imageLoadTraceData.ImageBase;
int imageSize = imageLoadTraceData.ImageSize;
string fullName = fileName + "@" + imageBase.ToString();
if (!ImageMap.ContainsKey(fullName))
{
ImageInfo imageInfo = new ImageInfo(Path.GetFileName(fileName), imageBase, imageSize);
ImageMap.Add(fullName, imageInfo);
}
}
break;
}
case "Image/Load":
{
ImageLoadTraceData imageLoadTraceData = (ImageLoadTraceData)data;
if (imageLoadTraceData.ProcessID == benchmarkPid)
{
string fileName = imageLoadTraceData.FileName;
ulong imageBase = imageLoadTraceData.ImageBase;
int imageSize = imageLoadTraceData.ImageSize;
// Suppress ngen images here, otherwise we lose visibility
// into ngen methods...
if (fileName.Contains(".ni."))
{
break;
}
string fullName = fileName + "@" + imageBase.ToString();
if (!ImageMap.ContainsKey(fullName))
{
ImageInfo imageInfo = new ImageInfo(Path.GetFileName(fileName), imageBase, imageSize);
ImageMap.Add(fullName, imageInfo);
}
}
break;
}
case "PerfInfo/PMCSample":
{
PMCCounterProfTraceData traceData = (PMCCounterProfTraceData)data;
if (traceData.ProcessID == benchmarkPid)
{
ulong instructionPointer = traceData.InstructionPointer;
// Not sure how to find the PMC reload interval... sigh
ulong count = 1;
UpdateSampleCountMap(instructionPointer, count);
UpdateThreadCountMap(traceData.ThreadID, count);
}
break;
}
}
};
source.Clr.All += delegate(TraceEvent data)
{
if (allEventCounts.ContainsKey(data.EventName))
{
allEventCounts[data.EventName]++;
}
else
{
allEventCounts[data.EventName] = 1;
}
if (data.ProcessID == benchmarkPid)
{
if (eventCounts.ContainsKey(data.EventName))
{
eventCounts[data.EventName]++;
}
else
{
eventCounts[data.EventName] = 1;
}
switch (data.EventName)
{
case "Method/JittingStarted":
{
MethodJittingStartedTraceData jitStartData = (MethodJittingStartedTraceData)data;
JitInvocation jitInvocation = new JitInvocation();
jitInvocation.ThreadId = jitStartData.ThreadID;
jitInvocation.MethodId = jitStartData.MethodID;
jitInvocation.InitialThreadCount = ThreadCountMap[jitInvocation.ThreadId];
ActiveJitInvocations.Add(jitInvocation.ThreadId, jitInvocation);
AllJitInvocations.Add(jitInvocation);
break;
}
case "Method/LoadVerbose":
{
MethodLoadUnloadVerboseTraceData loadUnloadData = (MethodLoadUnloadVerboseTraceData)data;
if (ActiveJitInvocations.ContainsKey(loadUnloadData.ThreadID))
{
JitInvocation j = ActiveJitInvocations[loadUnloadData.ThreadID];
ActiveJitInvocations.Remove(j.ThreadId);
j.FinalThreadCount = ThreadCountMap[j.ThreadId];
if (j.FinalThreadCount < j.InitialThreadCount)
{
Console.WriteLine("eh? negative jit count...");
}
else
{
JitSampleCount += j.FinalThreadCount - j.InitialThreadCount;
}
}
else
{
// ?
}
break;
}
case "Method/UnloadVerbose":
{
// Pretend this is an "image"
MethodLoadUnloadVerboseTraceData loadUnloadData = (MethodLoadUnloadVerboseTraceData)data;
string fullName = GetName(loadUnloadData);
string key = fullName + "@" + loadUnloadData.MethodID.ToString("X");
if (!ImageMap.ContainsKey(key))
{
ImageInfo methodInfo = new ImageInfo(fullName, loadUnloadData.MethodStartAddress,
loadUnloadData.MethodSize);
ImageMap.Add(key, methodInfo);
methodInfo.IsJitGeneratedCode = true;
methodInfo.IsJittedCode = loadUnloadData.IsJitted;
}
//else
//{
// Console.WriteLine("eh? see method {0} again in rundown", fullName);
//}
break;
}
}
}
};
source.Process();
}
AttributeSampleCounts();
//foreach (var e in allEventCounts)
//{
// Console.WriteLine("Event {0} occurred {1} times", e.Key, e.Value);
//}
//foreach (var e in processCounts)
//{
// Console.WriteLine("Process {0} had {1} events", e.Key, e.Value);
//}
if (!eventCounts.ContainsKey("PerfInfo/PMCSample"))
{
Console.WriteLine("No PMC events seen, sorry.");
}
else
{
ulong InstrsPerEvent = 65536;
ulong pmcEvents = eventCounts["PerfInfo/PMCSample"];
Console.WriteLine("InstRetired for {0}: {1} events, {2:E} instrs",
benchmarkName, pmcEvents, pmcEvents * InstrsPerEvent);
Console.WriteLine("Jitting : {0:00.00%} ({1} methods)",
(double)JitSampleCount / TotalSampleCount, AllJitInvocations.Count);
// Console.WriteLine(" JitInterface : {0:00.00%}", (double) JitSampleCount - JitDllSampleCount);
Console.WriteLine("Jit-generated code: {0:00.00%}", (double)JitGeneratedCodeSampleCount / TotalSampleCount);
Console.WriteLine(" Jitted code : {0:00.00%}", (double)JittedCodeSampleCount / TotalSampleCount);
Console.WriteLine();
double ufrac = (double)UnknownImageCount / TotalSampleCount;
if (ufrac > 0.002)
{
Console.WriteLine("{0:00.00%} {1,-8:G3} {2} {3}",
ufrac,
UnknownImageCount * InstrsPerEvent,
"? ",
"Unknown");
}
// Collect up significant counts
List <ImageInfo> significantInfos = new List <ImageInfo>();
foreach (var i in ImageMap)
{
double frac = (double)i.Value.SampleCount / TotalSampleCount;
if (frac > 0.002)
{
significantInfos.Add(i.Value);
}
}
significantInfos.Sort(ImageInfo.MoreSamples);
foreach (var i in significantInfos)
{
Console.WriteLine("{0:00.00%} {1,-8:G3} {2} {3}",
(double)i.SampleCount / TotalSampleCount,
i.SampleCount * InstrsPerEvent,
i.IsJitGeneratedCode ? (i.IsJittedCode ? "jit " : "prejit") : "native",
i.Name);
}
}
}
private void ReleaseProcessingSession()
{
if ( this.eventSource != null ) {
this.eventSource.Dispose();
this.eventSource = null;
}
}
/// <summary>
/// Wire up parsing of CLR event data from the specified ETWTraceEventSource.
/// </summary>
/// <param name="eventSource">The ETWTraceEventSource from which to parse the data.</param>
private void ParseClrTraceEvents(ETWTraceEventSource eventSource)
{
if (m_clrEvents == ClrTraceEventParser.Keywords.None)
return;
var clrTraceEventParser = new ClrTraceEventParser(eventSource);
// iterate over each set bit, wiring up a callback to parse the data
ulong eventBits = (ulong)m_clrEvents;
int bitPos = 0;
while (eventBits > 0)
{
// cycle through until a set bit is found
while ((((ulong)eventBits) & (ulong)(1 << bitPos)) == 0)
{
++bitPos;
Debug.Assert(bitPos < 64);
}
var bitVal = (ulong)(1 << bitPos);
// now strip it from eventBits and covert it to its enum value
eventBits ^= bitVal;
ClrTraceEventParser.Keywords clrEvent = (ClrTraceEventParser.Keywords)bitVal;
// aggregate the high and low events if both are available (enabling both provides a more complete value)
if ((clrEvent & ClrTraceEventParser.Keywords.GCSampledObjectAllocationHigh) == ClrTraceEventParser.Keywords.GCSampledObjectAllocationHigh ||
(clrEvent & ClrTraceEventParser.Keywords.GCSampledObjectAllocationLow) == ClrTraceEventParser.Keywords.GCSampledObjectAllocationLow ||
(clrEvent & ClrTraceEventParser.Keywords.GCAllObjectAllocation) == ClrTraceEventParser.Keywords.GCAllObjectAllocation)
{
if (!m_aed.ClrEventsData.ContainsKey(ClrPerfEvents.GCBytesAllocated))
m_aed.AddData(new EventDataScalarLong<ClrPerfEvents>(ClrPerfEvents.GCBytesAllocated));
var gcBytesAllocated = (EventDataScalarLong<ClrPerfEvents>)m_aed.ClrEventsData[ClrPerfEvents.GCBytesAllocated];
clrTraceEventParser.GCSampledObjectAllocation += delegate(GCSampledObjectAllocationTraceData data)
{
if (string.Compare(data.ProcessName, m_process, true) == 0)
{
gcBytesAllocated.Value += data.TotalSizeForTypeSample;
m_processFound = true;
}
};
}
else
{
Console.WriteLine("WARNING: CLR event {0} NYI for reporting.", clrEvent);
}
}
}
public void Load(string fileName)
{
ETWTraceEventSource source = new ETWTraceEventSource(fileName);
RegisteredTraceEventParser parser = new RegisteredTraceEventParser(source);
parser.All += Parser_All;
source.Process();
}
