/// <summary>
/// Dump the dot net Heap for process 'processID' to the etl file name 'etlFileName'. Send diagnostics to 'log'.
/// If 'memoryGraph is non-null also update it to contain the heap Dump. If null you get just the ETL file.
/// returns true if successful.
/// </summary>
static public bool DumpAsEtlFile(int processID, string etlFileName, TextWriter log, MemoryGraph memoryGraph = null, DotNetHeapInfo dotNetInfo = null)
{
bool success = false;
log.WriteLine("Starting ETW logging on File {0}", etlFileName);
using (var session = new TraceEventSession("PerfViewGCHeapETLSession", etlFileName))
{
session.EnableKernelProvider(KernelTraceEventParser.Keywords.Process | KernelTraceEventParser.Keywords.Thread | KernelTraceEventParser.Keywords.ImageLoad);
// Isolate this to a single process.
var options = new TraceEventProviderOptions()
{
ProcessIDFilter = new List <int>()
{
processID
}
};
// For non-project N we need module rundown to figure out the correct module name
session.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Verbose,
(ulong)(ClrRundownTraceEventParser.Keywords.Loader | ClrRundownTraceEventParser.Keywords.ForceEndRundown), options);
session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Informational,
(ulong)(ClrTraceEventParser.Keywords.GCHeapDump | ClrTraceEventParser.Keywords.GC | ClrTraceEventParser.Keywords.Type | ClrTraceEventParser.Keywords.Type | ClrTraceEventParser.Keywords.GCHeapAndTypeNames), options);
// Project N support.
session.EnableProvider(ClrTraceEventParser.NativeProviderGuid, TraceEventLevel.Informational,
(ulong)(ClrTraceEventParser.Keywords.GCHeapDump | ClrTraceEventParser.Keywords.GC | ClrTraceEventParser.Keywords.Type | ClrTraceEventParser.Keywords.Type | ClrTraceEventParser.Keywords.GCHeapAndTypeNames), options);
success = Dump(processID, memoryGraph, log, dotNetInfo);
log.WriteLine("Stopping ETW logging on {0}", etlFileName);
}
log.WriteLine("DumpAsETLFile returns. Success={0}", success);
return(success);
}
public bool EnableProvider(Config.TraceProvider provider)
{
switch (provider.Type)
{
case Config.TraceProviderType.kernel:
Output.Print("Skipping kernel provider: feature unimplemented");
break;
case Config.TraceProviderType.userguid:
Output.Print("Enabling user provider: " + provider.Guid);
mEtwSession.EnableProvider(provider.Guid);
break;
case Config.TraceProviderType.userid:
Output.Print("Enabling user provider: " + provider.UserId);
mEtwSession.EnableProvider(provider.UserId);
break;
default:
Output.Print("Error: Bad kernel provider type for " + provider.Guid.ToString());
break;
}
return(true);
}
public void CreateOrOpenEventSessionTest()
{
string sessionName = "hiahiaSession";
Assert.IsNull(TraceEventSession.GetActiveSession(sessionName));
string logDir = TestUtility.TestDirectory + "\\hiahiaLogs";
if (!Directory.Exists(logDir))
{
Directory.CreateDirectory(logDir);
}
string logfile = logDir + "\\hiahia.etl";
TraceEventSession session = Utility.CreateOrOpenEventSession(sessionName, logfile);
session.EnableProvider(TraceEventProvider.Instance.Name);
// create again
session = Utility.CreateOrOpenEventSession(sessionName, logfile);
session.EnableProvider(TraceEventProvider.Instance.Name);
session.Dispose();
Assert.IsNull(TraceEventSession.GetActiveSession(sessionName));
Directory.Delete(logDir, recursive: true);
}
private void SetupProviders(TraceEventSession session)
{
// Note: the kernel provider MUST be the first provider to be enabled
// If the kernel provider is not enabled, the callstacks for CLR events are still received
// but the symbols are not found (except for the application itself)
// TraceEvent implementation details triggered when a module (image) is loaded
session.EnableKernelProvider(
KernelTraceEventParser.Keywords.ImageLoad |
KernelTraceEventParser.Keywords.Process,
KernelTraceEventParser.Keywords.None
);
session.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Verbose, // this is needed in order to receive AllocationTick_V2 event
(ulong)(
// required to receive AllocationTick events
ClrTraceEventParser.Keywords.GC |
ClrTraceEventParser.Keywords.Jit | // Turning on JIT events is necessary to resolve JIT compiled code
ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | // This is needed if you want line number information in the stacks
ClrTraceEventParser.Keywords.Loader | // You must include loader events as well to resolve JIT compiled code.
ClrTraceEventParser.Keywords.Stack // Get the callstack for each event
)
);
// this provider will send events of already JITed methods
session.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Verbose,
(ulong)(
ClrTraceEventParser.Keywords.Jit | // We need JIT events to be rundown to resolve method names
ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | // This is needed if you want line number information in the stacks
ClrTraceEventParser.Keywords.Loader | // As well as the module load events.
ClrTraceEventParser.Keywords.StartEnumeration // This indicates to do the rundown now (at enable time)
));
}
public FPSMonitor()
{
//create ETW session and register providers
EtwSession = new TraceEventSession("mysess");
EtwSession.StopOnDispose = true;
EtwSession.EnableProvider("Microsoft-Windows-D3D9");
EtwSession.EnableProvider("Microsoft-Windows-DXGI");
watch = new Stopwatch();
//handle event
EtwSession.Source.AllEvents += data =>
{
//filter out frame presentation events
if (((int)data.ID == EventID_D3D9PresentStart && data.ProviderGuid == D3D9_provider) || ((int)data.ID == EventID_DxgiPresentStart && data.ProviderGuid == DXGI_provider))
{
long t = watch.ElapsedMilliseconds;
lock (sync)
{
if (timestamps.Count == MaxNumberSamples)
{
timestamps.RemoveAt(0);
}
timestamps.Add(t);
}
}
};
}
public static void StartCapture(string newSessionName = null)
{
if (newSessionName != null)
{
sessionName = newSessionName;
}
using (var session = new TraceEventSession(sessionName))
{
if (TraceEventSession.IsElevated() != true)
{
Console.Out.WriteLine("[!] run as admin");
return;
}
SetupCtrlCHandler(() => { if (session != null)
{
session.Stop();
}
});
session.Source.Dynamic.All += EventCallback;
session.EnableProvider(UsbUcx);
session.EnableProvider(UsbPort);
Console.WriteLine("starting capture ...");
session.Source.Process();
}
}
public void StartEventTrace(int processId)
{
_isFinished = new ManualResetEventSlim(false);
_session = new TraceEventSession("InliningAnalyzerSession");
_session.Source.Clr.MethodInliningSucceeded += Clr_MethodInliningSucceeded;
_session.Source.Clr.MethodInliningFailed += Clr_MethodInliningFailed;
_session.Source.Clr.MethodInliningFailedAnsi += Clr_MethodInliningFailedAnsi;
_session.Source.Clr.MethodJittingStarted += Clr_MethodJittingStarted;
_session.Source.Dynamic.All += Dynamic_All;
_session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)(ClrTraceEventParser.Keywords.Jit | ClrTraceEventParser.Keywords.JitTracing),
new TraceEventProviderOptions
{
ProcessIDFilter = new List <int> {
processId
},
EventIDsToEnable = new List <int> {
EVENTID_JITTING_STARTED, EVENTID_INLINING_SUCCEEDED, EVENTID_INLINING_FAILED, EVENTID_INLINING_FAILEDANSI
}
});
_session.EnableProvider(EVENTSOURCENAME, TraceEventLevel.Informational, options:
new TraceEventProviderOptions
{
ProcessIDFilter = new List <int> {
processId
}
});
Task.Run(() => _session.Source.Process());
}
public static void StartTrace()
{
Console.WriteLine("******************** ETW Keylogger ********************");
if (TraceEventSession.IsElevated() != true)
{
Console.WriteLine("Must be Admin to run this utility.");
Debugger.Break();
return;
}
Console.WriteLine("Press Ctrl-C to stop monitoring.");
using (var userSession = new TraceEventSession("ObserveEventSource"))
{
userSession.StopOnDispose = true;
// Set up Ctrl-C to stop trace sessions
SetupCtrlCHandler(() =>
{
userSession?.Stop();
});
using (var source = new ETWTraceEventSource("ObserveEventSource", TraceEventSourceType.Session))
{
var usb2EventParser = new DynamicTraceEventParser(source);
usb2EventParser.All += delegate(TraceEvent data)
{
byte[] usbPayload = null;
if (data.EventData().Length >= 243)
{
usbPayload = data.EventData().Skip(115).ToArray();
var message = new USBMessage(usbPayload);
if (message.Header.Length >= 128 && message.BulkOrInterrupt.Payload != null)
{
if (ValidatePayload(message.BulkOrInterrupt.Payload))
{
try
{
KeyboardKeymap key = (KeyboardKeymap)message.BulkOrInterrupt.Payload[(byte)PayloadKeys.KeyCode];
KeyboardModifier modifier = (KeyboardModifier)message.BulkOrInterrupt.Payload[(byte)PayloadKeys.Modifier];
Console.WriteLine($"Key modifier: {modifier} - Key pressed: {key} ");
Console.WriteLine(BitConverter.ToString(message.BulkOrInterrupt.Payload));
}
catch (Exception)
{
Console.WriteLine("Can't decode keypress");
}
}
}
}
};
userSession.EnableProvider(USB2_PROVIDERNAME);
userSession.EnableProvider(USB3_PROVIDERNAME);
source.Process();
}
}
}
private static void RealTimeSession()
{
if (options.ParsedClrKeywords == 0 &&
options.ParsedKernelKeywords == KernelTraceEventParser.Keywords.None &&
options.OtherProviders.Count == 0)
{
Bail("No events to collect");
}
Console.CancelKeyPress += (_, __) => CloseSession();
if (options.DurationInSeconds > 0)
{
Task.Delay(TimeSpan.FromSeconds(options.DurationInSeconds))
.ContinueWith(_ => CloseSession());
}
using (session = new TraceEventSession("etrace-realtime-session"))
{
if (options.ParsedKernelKeywords != KernelTraceEventParser.Keywords.None)
{
session.EnableKernelProvider(options.ParsedKernelKeywords);
}
if (options.ParsedClrKeywords != 0)
{
session.EnableProvider(ClrTraceEventParser.ProviderGuid,
matchAnyKeywords: (ulong)options.ParsedClrKeywords);
}
if (options.OtherProviders.Any())
{
foreach (var provider in options.OtherProviders)
{
Guid guid;
if (Guid.TryParse(provider, out guid))
{
session.EnableProvider(Guid.Parse(provider));
}
else
{
guid = TraceEventProviders.GetProviderGuidByName(provider);
if (guid != Guid.Empty)
{
session.EnableProvider(guid);
}
}
}
}
if (options.IsOutFile)
{
outRelogger = new ETWReloggerTraceEventSource(session.SessionName, TraceEventSourceType.Session, options.OutFile);
isOutReloggerSet = true;
ProcessTrace(outRelogger);
}
else
{
ProcessTrace(session.Source);
}
}
}
static void RunTest()
{
var tmfDirectory = ".";
var sessionName = "My Real Time Session";
TraceEventSession session = null;
ETWTraceEventSource source = null;
bool started = false;
// Start a thread to listen for incoming events in real time.
var listenThread = new System.Threading.Thread(delegate()
{
using (session = new TraceEventSession(sessionName, null))
{
session.StopOnDispose = true;
using (source = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session))
{
session.EnableProvider(WPPProviderGuid1, (TraceEventLevel)200, ulong.MaxValue);
session.EnableProvider(WPPProviderGuid2, (TraceEventLevel)200, ulong.MaxValue);
started = true;
// This is my callback. Right now I just print.
Action <TraceEvent> print = delegate(TraceEvent data) { Console.WriteLine(data.ToString()); };
// Wire up callbacks
#if false // Other parsers you could enable
var dynamicParser = source.Dynamic; // EventSources
dynamicParser.ReadAllManifests("."); // If we have explicit manifests we wish to use (but not register with the OS).
dynamicParser.All += print;
var registeredParser = new RegisteredTraceEventParser(source); // OS build in events
registeredParser.All += print;
#endif
var wppParser = new WppTraceEventParser(source, tmfDirectory); // WPP where we have the TMF files in 'tmfDirectory'
wppParser.All += print;
source.UnhandledEvent += print; // Optional. Shows events you don't recognize. probably worth investigating.
source.Process(); // listen for incomming events.
}
}
});
// Wait for startup
while (!started)
{
System.Threading.Thread.Sleep(1);
}
Console.WriteLine("Listening for 1 min");
System.Threading.Thread.Sleep(60000);
// To stop listening
Console.WriteLine("Stopping listening");
source.StopProcessing();
source.Dispose();
session.Dispose();
Console.WriteLine("Done");
}
public void Watch(string providerName)
{
// Turn on the process events (includes starts and stops).
session.EnableProvider(providerName);
session.Source.Dynamic.All += traceEvent =>
{
output(traceEvent.ToString());
};
}
protected void EnabledDefaultProviders(TraceEventSession session, TraceEventProviderOptions options = null)
{
// This provider is required to get ActivityID support on TraceEvents.
session.EnableProvider(
TplEtwProviderTraceEventParser.ProviderGuid,
TraceEventLevel.Informational,
(ulong)TplEtwProviderTraceEventParser.Keywords.TasksFlowActivityIds,
options);
session.EnableProvider(DotNetRuntimeProviderGuid, options: options);
session.EnableProvider(XamlProviderGuid, options: options);
}
public static EventListener Create(Guid eventSourceGuid, string sessionName, double eventCounterIntervalSeconds)
{
var session = new TraceEventSession(sessionName);
TraceEventProviderOptions options = new TraceEventProviderOptions("EventCounterIntervalSec", eventCounterIntervalSeconds.ToString()); //I'm just guessing what the args should be...
session.EnableProvider(eventSourceGuid, providerLevel: TraceEventLevel.Verbose, matchAnyKeywords: ulong.MaxValue, options: options);
var source = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session);
var e = new EventListener(session, source);
source.Dynamic.All += delegate(TraceEvent data)
{
if (data.ProviderGuid != eventSourceGuid)
{
throw new Exception();
}
if (data.EventName == "EventCounters")
{
string s = data.PayloadString(0).Replace("∞", "0");
EventCounterData ed = Parse <EventCounterData>(s);
e.EventCounterEvent?.Invoke(MsSinceUnixEpoch(data.TimeStamp), ed);
}
};
return(e);
}
/// <summary>
/// Starts the ETW session, and processes the stack samples that come in. This method
/// does not return until another thread calls <see cref="Stop"/> to stop the session.
/// While this method is executing, live stack aggregates can be obtained from the
/// <see cref="Stacks"/> property, which is thread-safe.
/// </summary>
public void Start()
{
_session = new TraceEventSession($"LiveStacks-{Process.GetCurrentProcess().Id}");
// TODO Make the CPU sampling interval configurable, although changing it doesn't seem to work in a VM?
// _session.CpuSampleIntervalMSec = 10.0f;
// TODO Should we use _session.StackCompression? What would the events look like?
if (_provider == "kernel")
{
_session.EnableKernelProvider(_kernelKeyword, stackCapture: _kernelKeyword);
_session.Source.Kernel.StackWalkStack += OnKernelStackEvent;
}
if (_provider == "clr")
{
_session.EnableProvider(
ClrTraceEventParser.ProviderGuid,
matchAnyKeywords: (ulong)(_clrKeyword | ClrTraceEventParser.Keywords.Stack));
_session.Source.Clr.All += OnAnyClrEvent;
_session.Source.Clr.ClrStackWalk += OnClrStackEvent;
}
_session.Source.Process();
}
protected override void EnableProviders(TraceEventSession traceEventSession)
{
traceEventSession.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Verbose,
(ulong)ClrTraceEventParser.Keywords.GC);
}
static void RegisterEventListener(TraceEventSession userSession)
{
var options = new TraceEventProviderOptions();
options.AddArgument("EventCounterIntervalSec", _config.EventCounterIntervalInSeconds.ToString());
foreach (var eventSource in _config.EventSources)
{
userSession.EnableProvider(eventSource.Name, TraceEventLevel.Always, (ulong)EventKeywords.None, options);
// Create a stream of the 'EventCounters' event source events
IObservable <TraceEvent> eventStream = userSession.Source.Dynamic.Observe(eventSource.Name, "EventCounters");
eventStream.Subscribe(onNext: traceEvent =>
{
var payload = traceEvent.PayloadValue(0) as IDictionary <string, object>;
if (payload != null)
{
var key = $"{traceEvent.ProviderName}-{payload["Name"]}";
var eventCounterRow = _eventCounters[key];
for (var i = 0; i < _config.Columns.Count; i++)
{
var rowDataCell = eventCounterRow[i];
rowDataCell.UpdateData(payload[_config.Columns[i].Name]?.ToString());
}
}
});
}
// OK we are all set up, time to listen for events and pass them to the observers.
userSession.Source.Process();
}
static void Main(string[] args)
{
using (var session = new TraceEventSession("spotless-ppid-spoofing"))
{
Console.CancelKeyPress += delegate {
session.Source.StopProcessing();
session.Dispose();
};
session.EnableProvider("Microsoft-Windows-Kernel-Process", Microsoft.Diagnostics.Tracing.TraceEventLevel.Always, 0x10);
var parser = session.Source.Dynamic;
parser.All += e => {
if (e.OpcodeName == "Start" && Regex.IsMatch(e.FormattedMessage.ToLower(), "werfault") == false)
{
string[] messageBits = e.FormattedMessage.Replace(",", string.Empty).Split(' ');
int PID = int.Parse(messageBits[1]);
int PPID = int.Parse(messageBits[10]);
int realPPID = e.ProcessID;
if (PPID != realPPID)
{
// this may fail if the process is already gone.
string processName = Process.GetProcessById(PID).ProcessName;
Console.WriteLine($"{e.TimeStamp} PPID Spoofing detected: {processName} (PID={PID}) started by PPID={realPPID} rather than PPID={PPID}");
}
}
};
session.Source.Process();
}
}
private void generateJitRundownEvents(string dataFileName, string sessionName, int bufferSizeMb)
{
var rundownFileName = Path.ChangeExtension(dataFileName, ".clrRundown.etl");
using (var rundownSession = new TraceEventSession(sessionName + "Rundown", rundownFileName))
{
rundownSession.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)(ClrRundownTraceEventParser.Keywords.Default));
// Poll until 2 second goes by without growth.
for (var prevLength = new FileInfo(rundownFileName).Length; ;)
{
Thread.Sleep(TimeSpan.FromSeconds(2));
var newLength = new FileInfo(rundownFileName).Length;
if (newLength == prevLength)
{
break;
}
prevLength = newLength;
}
var eventsLostClr = rundownSession.EventsLost;
Dispatcher.BeginInvoke(
new Action(() =>
{
EventsLostClrLabel.Content = eventsLostClr;
}));
}
}
private void ProcessEtwEvents()
{
// setup process filter if any
TraceEventProviderOptions options = null;
if (_processId != -1)
{
options = new TraceEventProviderOptions()
{
ProcessIDFilter = new List <int>()
{
_processId
},
};
}
// register handlers for events on the session source
// --------------------------------------------------
RegisterListeners(_session.Source);
// decide which provider to listen to with filters if needed
_session.EnableProvider(
ClrTraceEventParser.ProviderGuid, // CLR provider
((_filter & EventFilter.AllocationTick) == EventFilter.AllocationTick) ?
TraceEventLevel.Verbose : TraceEventLevel.Informational,
GetKeywords(),
options
);
// this is a blocking call until the session is disposed
_session.Source.Process();
}
static void UserLogon()
{
Console.WriteLine("Waiting for a user to log on...");
var sessionName = "UserSession"; //Change this for OPSEC
using (var session = new TraceEventSession(sessionName, null))
{
session.StopOnDispose = true;
using (var source = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session)) //Use a realtime session
{
var parser = new RegisteredTraceEventParser(source);
parser.All += delegate(TraceEvent data)
{
string message = data.FormattedMessage;
if (!string.IsNullOrEmpty(message) && message.Contains("Authentication stopped. Result 0"))
{
Console.WriteLine("User login detected");
DoEvil();
}
};
Guid provider = new Guid("DBE9B383-7CF3-4331-91CC-A3CB16A3B538");
session.EnableProvider(provider, TraceEventLevel.Verbose);
source.Process();
Console.CancelKeyPress += (object s, ConsoleCancelEventArgs args) => session.Stop();
session.Dispose();
};
}
}
public void Test_WriteEvent_WithTraceEvent()
{
const string exceptionMessage = "KABUM";
var completed = Task.Factory.StartNew(
() =>
{
using (var session = new TraceEventSession($"TestSession_{nameof(Test_WriteEvent_WithTraceEvent)}"))
{
session.Source.Dynamic.AddCallbackForProviderEvent(
ErrorEventSource.EventSourceName,
nameof(ErrorEventSource.Tasks.ExceptionEvent),
e =>
{
e.PayloadByName("message").Should().Be(exceptionMessage);
e.PayloadByName("eventPayload").Should().NotBeNull();
// ReSharper disable once AccessToDisposedClosure
session.Source?.Dispose();
});
session.EnableProvider(ErrorEventSource.EventSourceName);
Task.Factory.StartNew(() =>
{
Task.Delay(TimeSpan.FromSeconds(3));
BigBrother.Write(new ExceptionEvent(new Exception(exceptionMessage)));
});
session.Source.Process();
}
})
.Wait(TimeSpan.FromSeconds(30));
completed.Should().BeTrue();
}
private static int SubscribeAndProcessCloudBuildEvents()
{
if (!(TraceEventSession.IsElevated() ?? false))
{
Error("Not elevated; exiting");
return(-1);
}
// BuildXL.Tracing.ETWLogger guid
if (!Guid.TryParse("43b71382-88db-5427-89d5-0b46476f8ef4", out Guid guid))
{
Error("Could not parse guid; exiting");
return(-1);
}
Console.WriteLine("Listening for cloud build events");
// Create an unique session
string sessionName = "DropDaemon ETW Session";
// the null second parameter means 'real time session'
using (TraceEventSession traceEventSession = new TraceEventSession(sessionName, null))
{
// Note that sessions create a OS object (a session) that lives beyond the lifetime of the process
// that created it (like Files), thus you have to be more careful about always cleaning them up.
// An importantly way you can do this is to set the 'StopOnDispose' property which will cause
// the session to
// stop (and thus the OS object will die) when the TraceEventSession dies. Because we used a 'using'
// statement, this means that any exception in the code below will clean up the OS object.
traceEventSession.StopOnDispose = true;
traceEventSession.EnableProvider(guid, matchAnyKeywords: (ulong)Keywords.CloudBuild);
// Prepare to read from the session, connect the ETWTraceEventSource to the session
using (ETWTraceEventSource etwTraceEventSource = new ETWTraceEventSource(
sessionName,
TraceEventSourceType.Session))
{
DynamicTraceEventParser dynamicTraceEventParser = new DynamicTraceEventParser(etwTraceEventSource);
dynamicTraceEventParser.All += traceEvent =>
{
Possible <CloudBuildEvent, Failure> possibleEvent = CloudBuildEvent.TryParse(traceEvent);
if (!possibleEvent.Succeeded)
{
Error(possibleEvent.Failure.ToString());
return;
}
CloudBuildEvent eventObj = possibleEvent.Result;
Console.WriteLine("*** Event received: " + eventObj.Kind);
};
etwTraceEventSource.Process();
}
}
Console.WriteLine("FINISHED");
Thread.Sleep(100000);
return(0);
}
/// <summary>
/// CollectData turn on logging of data from 'eventSourceName' to the file 'dataFileName'.
/// It will then call EventGenerator.CreateEvents and wait 12 seconds for it to generate some data.
/// </summary>
static void CollectData(string eventSourceName, string dataFileName)
{
// Today you have to be Admin to turn on ETW events (anyone can write ETW events).
if (!(TraceEventSession.IsElevated() ?? false))
{
Out.WriteLine("To turn on ETW events you need to be Administrator, please run from an Admin process.");
Debugger.Break();
return;
}
// As mentioned below, sessions can outlive the process that created them. Thus you need a way of
// naming the session so that you can 'reconnect' to it from another process. This is what the name
// is for. It can be anything, but it should be descriptive and unique. If you expect multiple versions
// of your program to run simultaneously, you need to generate unique names (e.g. add a process ID suffix)
// however this is dangerous because you can leave data collection on if the program ends unexpectedly.
//
// In this case we tell the session to place the data in MonitorToFileData.etl.
var sessionName = "SimpleMontitorSession";
Out.WriteLine("Creating a '{0}' session writing to {1}", sessionName, dataFileName);
Out.WriteLine("Use 'logman query -ets' to see active sessions.");
Out.WriteLine("Use 'logman stop {0} -ets' to manually stop orphans.", sessionName);
using (var session = new TraceEventSession(sessionName, dataFileName)) // Since we give it a file name, the data goes there.
{
/* BY DEFAULT ETW SESSIONS SURVIVE THE DEATH OF THE PROESS THAT CREATES THEM! */
// Unlike most other resources on the system, ETW session live beyond the lifetime of the
// process that created them. This is very useful in some scenarios, but also creates the
// very real possibility of leaving 'orphan' sessions running.
//
// To help avoid this by default TraceEventSession sets 'StopOnDispose' so that it will stop
// the ETW session if the TraceEventSession dies. Thus executions that 'clean up' the TraceEventSession
// will clean up the ETW session. This covers many cases (including throwing exceptions)
//
// However if the process is killed manually (including control C) this cleanup will not happen.
// Thus best practices include
//
// * Add a Control C handler that calls session.Dispose() so it gets cleaned up in this common case
// * use the same session name run-to-run so you don't create many orphans.
//
// By default TraceEventSessions are in 'create' mode where it assumes you want to create a new session.
// In this mode if a session already exists, it is stopped and the new one is created.
//
// Here we install the Control C handler. It is OK if Dispose is called more than once.
Console.CancelKeyPress += delegate(object sender, ConsoleCancelEventArgs e) { session.Dispose(); };
// Enable my provider, you can call many of these on the same session to get other events.
var restarted = session.EnableProvider(MyEventSource.Log.Name);
if (restarted) // Generally you don't bother with this warning, but for the demo we do.
{
Out.WriteLine("The session {0} was already active, it has been restarted.", sessionName);
}
// Start another thread that Causes MyEventSource to create some events
// Normally this code as well as the EventSource itself would be in a different process.
EventGenerator.CreateEvents();
Out.WriteLine("Waiting 12 seconds for events to come in.");
Thread.Sleep(12000);
}
}
internal static void EnableProvider(TraceEventSession session, Guid providerId, EventLevel level, EventKeywords matchAnyKeyword)
{
session.EnableProvider(
providerId,
(TraceEventLevel)level,
(ulong)matchAnyKeyword);
}
public void SubscribeToSession(TraceEventSession session)
{
var parser = new SystemDiagnosticsTraceEventParser(session.Source);
parser.ReceiveLog += OnReceiveLog;
session.EnableProvider(SystemDiagnosticsTraceEventParser.ProviderGuid, TraceEventLevel.Always, 0xFFFFFFFF);
}
public CollectTraceEventsHelper(CommandLineOptions options)
{
if (TraceEventSession.IsElevated() != true)
throw new InvalidOperationException("Collecting perf events requires administrative privileges.");
if (options.ClrEvents.Events == ClrTraceEventParser.Keywords.None && options.KernelEvents == KernelTraceEventParser.Keywords.None)
throw new PowerArgs.ArgException("Must specify at least one CLR or kernel event.");
// verify session name
var existingSessions = TraceEventSession.GetActiveSessionNames();
if (options.Mode == ExecutionMode.Start && existingSessions.Contains(options.TestName))
throw new InvalidOperationException(string.Format("The session name '{0}' is already in use.", options.TestName));
else if (options.Mode == ExecutionMode.Stop && !existingSessions.Contains(options.TestName))
throw new InvalidOperationException(string.Format("The session name '{0}' does not exist.", options.TestName));
m_traceSession = new TraceEventSession(options.TestName, options.DataFile);
if (options.Mode == ExecutionMode.Start)
{
m_traceSession.BufferSizeMB = 512;
// starting a new session, enable providers
m_traceSession.EnableKernelProvider(options.KernelEvents);
m_traceSession.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Informational, (ulong)options.ClrEvents.Events);
// keep the session active after the process terminates
m_traceSession.StopOnDispose = false;
}
}
public void Test_EventSource_EtwManifestGeneration()
{
RemoteExecutor.Invoke(() =>
{
using (RemoteInvokeHandle handle = RemoteExecutor.Invoke(() =>
{
var es = new SimpleEventSource();
for (var i = 0; i < 100; i++)
{
es.WriteSimpleInt(i);
Thread.Sleep(100);
}
}))
{
var etlFileName = @"file.etl";
var tracesession = new TraceEventSession("testname", etlFileName);
tracesession.EnableProvider("SimpleEventSource");
Thread.Sleep(TimeSpan.FromSeconds(5));
tracesession.Flush();
// Sleep after requesting flush to ensure that the manifest payload generated
// is fully written to the etl file.
Thread.Sleep(TimeSpan.FromSeconds(5));
tracesession.DisableProvider("SimpleEventSource");
tracesession.Dispose();
Assert.True(VerifyManifestAndRemoveFile(etlFileName));
}
}).Dispose();
}
internal static void EnableProvider(
TraceEventSession session,
Guid providerId,
EventLevel level,
EventKeywords matchAnyKeyword,
IEnumerable <KeyValuePair <string, string> > arguments,
IEnumerable <string> processNamesToFilter,
bool sendManifest = true)
{
// Make explicit the invocation for requesting the manifest from the EventSource (Provider).
var argumentsDictionary = arguments.ToDictionary(kvp => kvp.Key, kvp => kvp.Value);
if (sendManifest)
{
argumentsDictionary["Command"] = "SendManifest";
}
var options =
new TraceEventProviderOptions
{
Arguments = argumentsDictionary,
ProcessNameFilter = processNamesToFilter.ToArray()
};
session.EnableProvider(providerId, (TraceEventLevel)level, (ulong)matchAnyKeyword, options);
}
internal static void EnableProvider(
TraceEventSession session,
Guid providerId,
EventLevel level,
EventKeywords matchAnyKeyword,
IEnumerable<KeyValuePair<string, string>> arguments,
IEnumerable<string> processNamesToFilter,
bool sendManifest = true)
{
// Make explicit the invocation for requesting the manifest from the EventSource (Provider).
var argumentsDictionary = arguments.ToDictionary(kvp => kvp.Key, kvp => kvp.Value);
if (sendManifest)
{
argumentsDictionary["Command"] = "SendManifest";
}
var options =
new TraceEventProviderOptions
{
Arguments = argumentsDictionary,
ProcessNameFilter = processNamesToFilter.ToArray()
};
session.EnableProvider(providerId, (TraceEventLevel)level, (ulong)matchAnyKeyword, options);
}
private static void BuildEtwProcesses(IEnumerable <ProcessInfo> processesToRun, int degreeOfParallelism)
{
using (TraceEventSession traceEventSession = new TraceEventSession("ReadyToRunTestSession"))
{
traceEventSession.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)(ClrTraceEventParser.Keywords.Jit | ClrTraceEventParser.Keywords.Loader));
using (ReadyToRunJittedMethods jittedMethods = new ReadyToRunJittedMethods(traceEventSession, processesToRun))
{
Task.Run(() =>
{
BuildProjects(processesToRun, jittedMethods, degreeOfParallelism);
traceEventSession.Stop();
});
}
traceEventSession.Source.Process();
}
// Append jitted method info to the logs
foreach (ProcessInfo processInfo in processesToRun)
{
if (processInfo.CollectJittedMethods)
{
using (StreamWriter logWriter = new StreamWriter(processInfo.LogPath, append: true))
{
logWriter.WriteLine($"Jitted methods ({processInfo.JittedMethods.Sum(moduleMethodsKvp => moduleMethodsKvp.Value.Count)} total):");
foreach (KeyValuePair <string, HashSet <string> > jittedMethodsPerModule in processInfo.JittedMethods)
{
foreach (string method in jittedMethodsPerModule.Value)
{
logWriter.WriteLine(jittedMethodsPerModule.Key + " -> " + method);
}
}
}
}
}
}
public EtwTracingInterceptorTest()
{
eventSession = new TraceEventSession(Guid.NewGuid().ToString());
var eventSourceGuid = TraceEventProviders.GetEventSourceGuidFromName("Microsoft-WindowsAzure");
eventSession.EnableProvider(eventSourceGuid);
}
public void Test_EventSource_EtwManifestGenerationRollover()
{
RemoteExecutor.Invoke(() =>
{
using (RemoteInvokeHandle handle = RemoteExecutor.Invoke(() =>
{
var es = new SimpleEventSource();
for (var i = 0; i < 100; i++)
{
es.WriteSimpleInt(i);
Thread.Sleep(100);
}
}))
{
var initialFileName = @"initialFile.etl";
var rolloverFileName = @"rolloverFile.etl";
var tracesession = new TraceEventSession("testname", initialFileName);
var max_retries = 50;
tracesession.EnableProvider("SimpleEventSource");
Thread.Sleep(TimeSpan.FromSeconds(5));
tracesession.Flush();
tracesession.SetFileName(rolloverFileName);
Thread.Sleep(TimeSpan.FromSeconds(5));
tracesession.Flush();
tracesession.DisableProvider("SimpleEventSource");
tracesession.Dispose();
bool initialFileHasManifest = false;
bool rollOverFileHasManifest = false;
for (int i = 0; i < max_retries; i++)
{
if (VerifyManifestAndRemoveFile(initialFileName))
{
initialFileHasManifest = true;
break;
}
Thread.Sleep(1000);
}
for (int i = 0; i < max_retries; i++)
{
if (VerifyManifestAndRemoveFile(rolloverFileName))
{
rollOverFileHasManifest = true;
break;
}
Thread.Sleep(1000);
}
Assert.True(initialFileHasManifest);
Assert.True(rollOverFileHasManifest);
}
}).Dispose();
}
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();
}
}
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();
}
}
}
static void Main(string[] args)
{
Console.WriteLine("\n FedAuth Debugger\n\n");
using (var session = new TraceEventSession("FedAuthDebuggerApp"))
{
session.Source.Dynamic.All += delegate(TraceEvent data)
{
if (!String.IsNullOrEmpty(data.FormattedMessage))
{
Console.WriteLine(" {0} - {1}", data.TimeStamp.ToString("HH:mm:ss"), data.FormattedMessage);
}
};
session.EnableProvider(
TraceEventProviders.GetEventSourceGuidFromName("FedAuthDebugger-Session"));
session.EnableProvider(
TraceEventProviders.GetEventSourceGuidFromName("FedAuthDebugger-Federation"));
session.Source.Process();
}
Console.ReadLine();
}
/// <summary>
/// Turning on providers and creating the file
/// </summary>
static void DataCollection(string dataFileName)
{
Out.WriteLine("Collecting 10 seconds of kernel and CLR events to a file, and then printing.");
Out.WriteLine();
Out.WriteLine("Start a .NET program while monitoring to see some events!");
Out.WriteLine();
if (TraceEventSession.IsElevated() != true)
{
Out.WriteLine("Must be elevated (Admin) to run this program.");
Debugger.Break();
return;
}
// Create one user mode session and one kernel mode session
Out.WriteLine("Creating a file mode session");
using (var session = new TraceEventSession("MonitorKernelAndClrEventsSession", dataFileName))
{
// Set up Ctrl-C to stop both user mode and kernel mode sessions
Console.CancelKeyPress += delegate(object sender, ConsoleCancelEventArgs cancelArgs)
{
Out.WriteLine("Insuring all ETW sessions are stopped.");
session.Stop(true); // true means don't throw on error
// Since we don't cancel the Ctrl-C we will terminate the process as normal for Ctrl-C
Out.WriteLine("OnCtrl C handler ending.");
};
// Enable the events we care about for the kernel in the kernel session
// For this instant the session will buffer any incoming events.
// THis has to be first, and it will fail if you are not on Win8.
session.EnableKernelProvider(
KernelTraceEventParser.Keywords.ImageLoad |
KernelTraceEventParser.Keywords.Process |
KernelTraceEventParser.Keywords.Thread);
// Enable the events we care about for the CLR (in the user session).
// unlike the kernel session, you can call EnableProvider on other things too.
// For this instant the session will buffer any incoming events.
session.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Informational,
(ulong)(ClrTraceEventParser.Keywords.Default));
Out.WriteLine("Collecting data for 10 seconds (run a .Net program to generate events).");
Thread.Sleep(10000);
Out.WriteLine("Stopping sessions");
} // Using clauses will insure that session are disposed (and thus stopped) before Main returns.
}
public void Start(Benchmark benchmark)
{
ProcessIdsUsedInRuns.Clear();
statsPerProcess.Clear();
var sessionName = GetSessionName("GC", benchmark, benchmark.Parameters);
session = new TraceEventSession(sessionName);
session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose,
(ulong)(ClrTraceEventParser.Keywords.GC));
// The ETW collection thread starts receiving events immediately, but we only
// start aggregating them after ProcessStarted is called and we know which process
// (or processes) we should be monitoring. Communication between the benchmark thread
// and the ETW collection thread is through the statsPerProcess concurrent dictionary
// and through the TraceEventSession class, which is thread-safe.
Task.Factory.StartNew(StartProcessingEvents, TaskCreationOptions.LongRunning);
}
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();
}
}
}
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 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();
}
}
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);
}
static void Main(string[] args)
{
using (var session = new TraceEventSession("TelemetrySession"))
{
session.EnableProvider("ETW-Insturmentation-Events");
session.Source.Dynamic.AddCallbackForProviderEvent("ETW-Insturmentation-Events", "StartTelemetry/Start", (data) =>
{
Console.WriteLine(data.ToString());
});
session.Source.Dynamic.AddCallbackForProviderEvent("ETW-Insturmentation-Events", "StartTelemetry/Stop", (data) =>
{
Console.WriteLine(data.ToString());
});
session.Source.Dynamic.AddCallbackForProviderEvent("ETW-Insturmentation-Events", "Info", (data) =>
{
Console.WriteLine(data.ToString());
});
session.Source.Process();
}
}
public static void Run()
{
var monitoringTimeSec = 10;
Out.WriteLine("******************** KernelAndClrMonitor DEMO (Win7) ********************");
Out.WriteLine("Printing both Kernel and CLR (user mode) events simultaneously");
Out.WriteLine("The monitor will run for a maximum of {0} seconds", monitoringTimeSec);
Out.WriteLine("Press Ctrl-C to stop monitoring early.");
Out.WriteLine();
Out.WriteLine("Start a .NET program to see some events!");
Out.WriteLine();
if (TraceEventSession.IsElevated() != true)
{
Out.WriteLine("Must be elevated (Admin) to run this program.");
Debugger.Break();
return;
}
// Set up Ctrl-C to stop both user mode and kernel mode sessions
Console.CancelKeyPress += (object sender, ConsoleCancelEventArgs cancelArgs) =>
{
StopSessions();
cancelArgs.Cancel = true;
};
// Note that because there are different sessions, the events may not be printed
// in time order since the different sessions may flush their buffers at different
// times. If you care, you must buffer the events and order them by event
// timestamp. Note that the timestamps however ARE accurate.
Out.WriteLine("Setup up threads to process the events");
// start processing kernel events on a thread pool thread
var task1 = Task.Run(() =>
{
// Note that TraceEventSession and EtwTraceEventParser are IN GENERAL NOT THREADSAFE,
// Normally this is not a hardship you just set up the session TraceDispacher on one
// thread. It is OK to call a session's Dispose() and 'Enable and Disable provider APIS
// from another thread, but things associated with ETWTraceEventSource and TraceEventParsers
// should all be on the same thread.
Out.WriteLine("Kernel event Thread Starting");
Out.WriteLine("Enabling Image load, thread and process kernel events.");
using (s_kernelSession = new TraceEventSession(KernelTraceEventParser.KernelSessionName))
{
// Enable the events we care about for the kernel in the kernel session
// For this instant the session will buffer any incoming events.
// If you only have to run on Win8 systems you can use one session for both.
// Here we turn in process, thread and Image load events.
s_kernelSession.EnableKernelProvider(
KernelTraceEventParser.Keywords.ImageLoad |
KernelTraceEventParser.Keywords.Process |
KernelTraceEventParser.Keywords.Thread);
// You should do all processing from a single source on a single thread.
// Thus call calls to .Source, or Process() should be on the same thread.
s_kernelSession.Source.Kernel.All += Print;
#if DEBUG
// in debug builds it is useful to see any unhandled events because they could be bugs.
s_kernelSession.Source.UnhandledEvents += Print;
#endif
// process events until Ctrl-C is pressed
Out.WriteLine("Waiting on kernel events.");
s_kernelSession.Source.Process();
}
Out.WriteLine("Thread 1 dieing");
});
// start processing CLR events on a thread pool thread
var task2 = Task.Run(() =>
{
// Note that TraceEventSession and EtwTraceEventParser are IN GENERAL NOT THREADSAFE,
// Normally this is not a hardship you just set up the session TraceDispacher on one
// thread. It is OK to call a session's Dispose() and 'Enable and Disable provider APIS
// from another thread, but things associated with ETWTraceEventSource and TraceEventParsers
// should all be on the same thread.
using (s_userSession = new TraceEventSession("MonitorKernelAndClrEventsSession"))
{
Out.WriteLine("Enabling CLR GC and Exception events.");
// Enable the events we care about for the CLR (in the user session).
// unlike the kernel session, you can call EnableProvider on other things too.
// For this instant the ;session will buffer any incoming events.
s_userSession.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Informational,
(ulong)(ClrTraceEventParser.Keywords.GC | ClrTraceEventParser.Keywords.Exception));
// s_userSession.Source.Clr.GCHeapStats += (GCHeapStatsTraceData data) => Out.WriteLine(" ", data.GenerationSize0);
Out.WriteLine("User event Thread Starting");
s_userSession.Source.Clr.All += Print;
#if DEBUG
// in debug builds it is useful to see any unhandled events because they could be bugs.
s_userSession.Source.UnhandledEvents += Print;
#endif
// process events until Ctrl-C is pressed or timeout expires
Out.WriteLine("Waiting on user events.");
s_userSession.Source.Process();
}
Out.WriteLine("Thread 2 dieing");
});
// Set up a timer to stop processing after monitoringTimeSec
var timer = new Timer(delegate(object state)
{
Out.WriteLine("Stopped Monitoring after {0} sec", monitoringTimeSec);
StopSessions();
}, null, monitoringTimeSec * 1000, Timeout.Infinite);
// Wait until tasks are complete
Out.WriteLine("Waiting for processing tasks to complete");
Task.WaitAll(task1, task2);
Out.WriteLine("Monitoring stopped");
timer.Dispose();
}
/// <summary>
/// CollectData turn on logging of data from 'eventSourceName' to the file 'dataFileName'.
/// It will then call EventGenerator.CreateEvents and wait 12 seconds for it to generate some data.
/// </summary>
static void CollectData(string eventSourceName, string dataFileName)
{
// Today you have to be Admin to turn on ETW events (anyone can write ETW events).
if (!(TraceEventSession.IsElevated() ?? false))
{
Out.WriteLine("To turn on ETW events you need to be Administrator, please run from an Admin process.");
Debugger.Break();
return;
}
// As mentioned below, sessions can outlive the process that created them. Thus you need a way of
// naming the session so that you can 'reconnect' to it from another process. This is what the name
// is for. It can be anything, but it should be descriptive and unique. If you expect multiple versions
// of your program to run simultaneously, you need to generate unique names (e.g. add a process ID suffix)
// however this is dangerous because you can leave data collection on if the program ends unexpectedly.
//
// In this case we tell the session to place the data in MonitorToFileData.etl.
var sessionName = "SimpleMontitorSession";
Out.WriteLine("Creating a '{0}' session writing to {1}", sessionName, dataFileName);
Out.WriteLine("Use 'logman query -ets' to see active sessions.");
Out.WriteLine("Use 'logman stop {0} -ets' to manually stop orphans.", sessionName);
using (var session = new TraceEventSession(sessionName, dataFileName)) // Since we give it a file name, the data goes there.
{
/* BY DEFAULT ETW SESSIONS SURVIVE THE DEATH OF THE PROESS THAT CREATES THEM! */
// Unlike most other resources on the system, ETW session live beyond the lifetime of the
// process that created them. This is very useful in some scenarios, but also creates the
// very real possibility of leaving 'orphan' sessions running.
//
// To help avoid this by default TraceEventSession sets 'StopOnDispose' so that it will stop
// the ETW session if the TraceEventSession dies. Thus executions that 'clean up' the TraceEventSession
// will clean up the ETW session. This covers many cases (including throwing exceptions)
//
// However if the process is killed manually (including control C) this cleanup will not happen.
// Thus best practices include
//
// * Add a Control C handler that calls session.Dispose() so it gets cleaned up in this common case
// * use the same session name run-to-run so you don't create many orphans.
//
// By default TraceEventSessions are in 'create' mode where it assumes you want to create a new session.
// In this mode if a session already exists, it is stopped and the new one is created.
//
// Here we install the Control C handler. It is OK if Dispose is called more than once.
Console.CancelKeyPress += delegate(object sender, ConsoleCancelEventArgs e) { session.Dispose(); };
// Enable my provider, you can call many of these on the same session to get other events.
var restarted = session.EnableProvider(MyEventSource.Log.Name);
if (restarted) // Generally you don't bother with this warning, but for the demo we do.
Out.WriteLine("The session {0} was already active, it has been restarted.", sessionName);
// Start another thread that Causes MyEventSource to create some events
// Normally this code as well as the EventSource itself would be in a different process.
EventGenerator.CreateEvents();
Out.WriteLine("Waiting 12 seconds for events to come in.");
Thread.Sleep(12000);
}
}
public static void Run()
{
var monitoringTimeSec = 10;
Out.WriteLine("******************** RealTimeTraceLog DEMO (win8) ********************");
Out.WriteLine("This program Shows how to use the real-time support in TraceLog");
Out.WriteLine("We do this by showing how to monitor exceptions in real time ");
Out.WriteLine();
Out.WriteLine("This code depends on a Feature of Windows 8.1 (combined user and kernel sessions)");
Out.WriteLine();
Out.WriteLine("Note that this support is currently experimental and subject to change");
Out.WriteLine();
Out.WriteLine("Monitoring .NET Module load and Exception events (with stacks).");
Out.WriteLine("Run some managed code (ideally that has exceptions) while the monitor is running.");
Out.WriteLine();
if (Environment.OSVersion.Version.Major * 10 + Environment.OSVersion.Version.Minor < 62)
{
Out.WriteLine("This demo only works on Win8 / Win 2012 and above)");
return;
}
TraceEventSession session = null;
// Set up Ctrl-C to stop both user mode and kernel mode sessions
Console.CancelKeyPress += (object sender, ConsoleCancelEventArgs cancelArgs) =>
{
if (session != null)
session.Dispose();
cancelArgs.Cancel = true;
};
// Cause an exception to be thrown a few seconds in (so we have something interesting to look at)
var exceptionGeneationTask = Task.Factory.StartNew(delegate
{
Thread.Sleep(3000);
ThrowException();
});
Timer timer = null;
// Create the new session to receive the events.
// Because we are on Win 8 this single session can handle both kernel and non-kernel providers.
using (session = new TraceEventSession("TraceLogSession"))
{
// Enable the events we care about for the kernel
// For this instant the session will buffer any incoming events.
// Enabling kernel events must be done before anything else.
// This will fail on Win7.
//
// Note that if you turn on the KernelTraceEventParser.Keywords.Profile, you can also get stacks for CPU sampling
// (every millisecond). (You can use the traceLogSource.Kernel.PerfInfoSample callback).
Out.WriteLine("Enabling Image load, Process and Thread events. These are needed to look up native method names.");
session.EnableKernelProvider(
// KernelTraceEventParser.Keywords.Profile | // If you want CPU sampling events
// KernelTraceEventParser.Keywords.ContextSwitch | // If you want context switch events
// KernelTraceEventParser.Keywords.Thread | // If you want context switch events you also need thread start events.
KernelTraceEventParser.Keywords.ImageLoad |
KernelTraceEventParser.Keywords.Process, /****** The second parameter indicates which kernel events should have stacks *****/
// KernelTraceEventParser.Keywords.ImageLoad | // If you want Stacks image load (load library) events
// KernelTraceEventParser.Keywords.Profile | // If you want Stacks for CPU sampling events
// KernelTraceEventParser.Keywords.ContextSwitch | // If you want Stacks for context switch events
KernelTraceEventParser.Keywords.None
);
Out.WriteLine("Enabling CLR Exception and Load events (and stack for those events)");
// We are monitoring exception events (with stacks) and module load events (with stacks)
session.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Informational,
(ulong)(ClrTraceEventParser.Keywords.Jit | // Turning on JIT events is necessary to resolve JIT compiled code
ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | // This is needed if you want line number information in the stacks
ClrTraceEventParser.Keywords.Loader | // You must include loader events as well to resolve JIT compiled code.
ClrTraceEventParser.Keywords.Exception | // We want to see the exception events.
ClrTraceEventParser.Keywords.Stack)); // And stacks on all CLR events where it makes sense.
// The CLR events turned on above will let you resolve JIT compiled code as long as the JIT compilation
// happens AFTER the session has started. To handle the case for JIT compiled code that was already
// compiled we need to tell the CLR to dump 'Rundown' events for all existing JIT compiled code. We
// do that here.
Out.WriteLine("Enabling CLR Events to 'catch up' on JIT compiled code in running processes.");
session.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Informational,
(ulong)(ClrTraceEventParser.Keywords.Jit | // We need JIT events to be rundown to resolve method names
ClrTraceEventParser.Keywords.JittedMethodILToNativeMap | // This is needed if you want line number information in the stacks
ClrTraceEventParser.Keywords.Loader | // As well as the module load events.
ClrTraceEventParser.Keywords.StartEnumeration)); // This indicates to do the rundown now (at enable time)
// Because we care about symbols in native code or NGEN images, we need a SymbolReader to decode them.
// There is a lot of messages associated with looking up symbols, but we don't want to clutter up
// The output by default, so we save it to an internal buffer you can ToString in debug code.
// A real app should make this available somehow to the user, because sooner or later you DO need it.
TextWriter SymbolLookupMessages = new StringWriter();
// TextWriter SymbolLookupMessages = Out; // If you want the symbol debug spew to go to the output, use this.
// By default a symbol Reader uses whatever is in the _NT_SYMBOL_PATH variable. However you can override
// if you wish by passing it to the SymbolReader constructor. Since we want this to work even if you
// have not set an _NT_SYMBOL_PATH, so we add the Microsoft default symbol server path to be sure/
var symbolPath = new SymbolPath(SymbolPath.SymbolPathFromEnvironment).Add(SymbolPath.MicrosoftSymbolServerPath);
SymbolReader symbolReader = new SymbolReader(SymbolLookupMessages, symbolPath.ToString());
Out.WriteLine("Open a real time TraceLog session (which understands how to decode stacks).");
using (TraceLogEventSource traceLogSource = TraceLog.CreateFromTraceEventSession(session))
{
// We use this action in the particular callbacks below. Basically we pass in a symbol reader so we can decode the stack.
// Often the symbol reader is a global variable instead.
Action<TraceEvent> PrintEvent = ((TraceEvent data) => Print(data, symbolReader));
// We will print Exceptions and ModuleLoad events. (with stacks).
traceLogSource.Clr.ExceptionStart += PrintEvent;
traceLogSource.Clr.LoaderModuleLoad += PrintEvent;
// traceLogSource.Clr.All += PrintEvent;
// If you want to see stacks for various other kernel events, uncomment these (you also need to turn on the events above)
traceLogSource.Kernel.PerfInfoSample += ((SampledProfileTraceData data) => Print(data, symbolReader));
// traceLogSource.Kernel.ImageLoad += ((ImageLoadTraceData data) => Print(data, symbolReader));
// process events until Ctrl-C is pressed or timeout expires
Out.WriteLine("Waiting {0} sec for Events. Run managed code to see data. ", monitoringTimeSec);
Out.WriteLine("Keep in mind there is a several second buffering delay");
// Set up a timer to stop processing after monitoringTimeSec
timer = new Timer(delegate(object state)
{
Out.WriteLine("Stopped Monitoring after {0} sec", monitoringTimeSec);
if (session != null)
session.Dispose();
session = null;
}, null, monitoringTimeSec * 1000, Timeout.Infinite);
traceLogSource.Process();
}
}
Out.WriteLine("Finished");
if (timer != null)
timer.Dispose(); // Turn off the timer.
}
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 EtwTracingInterceptorTest()
{
_eventSession = new TraceEventSession(Guid.NewGuid().ToString());
var eventSourceGuid = TraceEventProviders.GetEventSourceGuidFromName("Microsoft-WindowsAzure");
_eventSession.EnableProvider(eventSourceGuid);
}
public void TestSessionClosing()
{
LogManager.Shutdown(); // not needed by us
// set this just to make sure it isn't actually used.
LogManager.AllowEtwLogging = AllowEtwLoggingValues.Disabled;
File.Delete("fakesession.etl");
var s1 = new TraceEventSession(ETLFileLogger.SessionPrefix + "fakeSession", "fakeSession.etl");
s1.EnableProvider(TestLogger.Write.Guid, TraceEventLevel.Verbose);
s1.StopOnDispose = false;
TestLogger.Write.String("mc frontalot = nerdcore raps");
Assert.IsTrue(File.Exists("fakesession.etl"));
Assert.IsNotNull(TraceEventSession.GetActiveSession(ETLFileLogger.SessionPrefix + "fakeSession"));
s1.Dispose();
// so the session should still exist ...
Assert.IsNotNull(TraceEventSession.GetActiveSession(ETLFileLogger.SessionPrefix + "fakeSession"));
var s2 = new ETLFileLogger("fakeSession", "fakeSession.etl", 64);
s2.SubscribeToEvents(TestLogger.Write.Guid, EventLevel.Verbose);
TestLogger.Write.String("optimus rhyme = also rapping nerd");
s2.Dispose();
const int maxWait = 1000;
int slept = 0;
while (slept < maxWait)
{
if (TraceEventSession.GetActiveSession(ETLFileLogger.SessionPrefix + "fakeSession") == null)
{
break;
}
Thread.Sleep(maxWait / 10);
slept += maxWait / 10;
}
Assert.IsNull(TraceEventSession.GetActiveSession(ETLFileLogger.SessionPrefix + "fakeSession"));
}
private void StartListening()
{
Console.WriteLine( "Starting Listening for events" );
_session = new TraceEventSession( "MyRealTimeSession" ); // Create a session to listen for events
_session.Source.Dynamic.All += delegate(TraceEvent data) // Set Source (stream of events) from session.
{ // Get dynamic parser (knows about EventSources)
// Subscribe to all EventSource events
//OutputEvent( data.Dump() );
if (data.EventName != "JobStart" && data.EventName != "JobEnd" && data.EventName != "Step") return;
if (_hubConnection != null && _hubConnection.State == ConnectionState.Connected)
{
string jsonData = data.PayloadByName( "jsonData" ) as string;
object jobId = data.PayloadByName( "jobId" );
object jobRunId = data.PayloadByName( "jobRunId" );
Stopwatch watch = new Stopwatch();
watch.Restart();
if (string.IsNullOrEmpty( jsonData ))
{
if (data.EventName == "JobStart")
{
object jobName = data.PayloadByName( "jobName" ) as string;
_centralLogHubProxy.Invoke( data.EventName, jobId, jobName, jobRunId ).Wait();
}
else
{
_centralLogHubProxy.Invoke( data.EventName, jobId, jobRunId ).Wait();
}
}
else
{
_centralLogHubProxy.Invoke( data.EventName, jobId, jobRunId, jsonData ).Wait();
}
watch.Stop();
//Console.WriteLine( "sending took {0}ms",watch.ElapsedMilliseconds);
}
};
_session.StopOnDispose = true;
var eventSourceGuid = TraceEventProviders.GetEventSourceGuidFromName( GlobalDefines.EVENT_SOURCE_NAME ); // Get the unique ID for the eventSouce.
_session.EnableProvider( eventSourceGuid ); // Enable MyEventSource.
_session.Source.Process(); // Wait for incoming events (forever).
}
public static void Run()
{
var monitoringTimeSec = 10;
if (Environment.OSVersion.Version.Major * 10 + Environment.OSVersion.Version.Minor < 62)
{
Out.WriteLine("This demo only works on Win8 / Win 2012 an above)");
return;
}
Out.WriteLine("******************** KernelAndClrMonitor DEMO (Win 8) ********************");
Out.WriteLine("Printing both Kernel and CLR (user mode) events simultaneously");
Out.WriteLine("The monitor will run for a maximum of {0} seconds", monitoringTimeSec);
Out.WriteLine("Press Ctrl-C to stop monitoring early.");
Out.WriteLine();
Out.WriteLine("Start a .NET program to see some events!");
Out.WriteLine();
if (TraceEventSession.IsElevated() != true)
{
Out.WriteLine("Must be elevated (Admin) to run this program.");
Debugger.Break();
return;
}
TraceEventSession session = null;
// Set up Ctrl-C to stop both user mode and kernel mode sessions
Console.CancelKeyPress += (object sender, ConsoleCancelEventArgs cancelArgs) =>
{
if (session != null)
session.Dispose();
cancelArgs.Cancel = true;
};
// Set up a timer to stop processing after monitoringTimeSec
var timer = new Timer(delegate(object state)
{
Out.WriteLine("Stopped Monitoring after {0} sec", monitoringTimeSec);
if (session != null)
session.Dispose();
}, null, monitoringTimeSec * 1000, Timeout.Infinite);
// Create the new session to receive the events.
// Because we are on Win 8 this single session can handle both kernel and non-kernel providers.
using (session = new TraceEventSession("MonitorKernelAndClrEventsSession"))
{
// Enable the events we care about for the kernel
// For this instant the session will buffer any incoming events.
// Enabling kernel events must be done before anything else.
// This will fail on Win7.
Out.WriteLine("Enabling Image load, Process and Thread events.");
session.EnableKernelProvider(
KernelTraceEventParser.Keywords.ImageLoad |
KernelTraceEventParser.Keywords.Process |
KernelTraceEventParser.Keywords.Thread);
// Subscribe the events of interest. In this case we just print all events.
session.Source.Kernel.All += Print;
Out.WriteLine("Enabling CLR GC and Exception events.");
// Enable the events we care about for the CLR (in the user session).
// unlike the kernel session, you can call EnableProvider on other things too.
// For this instant the ;session will buffer any incoming events.
session.EnableProvider(
ClrTraceEventParser.ProviderGuid,
TraceEventLevel.Informational,
(ulong)(ClrTraceEventParser.Keywords.GC | ClrTraceEventParser.Keywords.Exception));
session.Source.Clr.All += Print;
#if DEBUG
// in debug builds it is useful to see any unhandled events because they could be bugs.
session.Source.UnhandledEvents += Print;
#endif
// process events until Ctrl-C is pressed or timeout expires
Out.WriteLine("Waiting for Events.");
session.Source.Process();
}
timer.Dispose(); // Turn off the timer.
}
/// <summary>
/// Listens the asynchronous.
/// </summary>
/// <param name="ct">The ct.</param>
/// <returns></returns>
private async Task ListenAsync(CancellationToken ct)
{
#region Log
Log(LogLevel.Information, $@"Creating a '{EtwConstants.SessionName}' session
Use 'logman query -ets' to see active sessions.
Use 'logman query -ets ""{EtwConstants.SessionName}""' for details
Use 'logman stop {EtwConstants.SessionName} -ets' to manually stop orphans.", null);
#endregion // Log
#region Documentation
/*****************************************************
* To listen to ETW events you need a session,
* which allows you to control which events will be produced
* Note that it is the session and not the source
* that buffers events, and by default sessions will buffer
* 64MB of events before dropping events.
* Thus even if you don't immediately connect up the source and
* read the events you should not lose them.
*
* As mentioned below, sessions can outlive the process that created them.
* Thus you may need a way of naming the session
* so that you can 'reconnect' to it from another process.
* This is what the name is for.
* It can be anything, but it should be descriptive and unique.
* If you expect multiple versions of your program
* to run simultaneously, you need to generate unique names
* (e.g. add a process ID suffix)
* however this is dangerous because you can leave data
* collection on if the program ends unexpectedly.
*****************************************************/
#endregion // Documentation
_session = new TraceEventSession(EtwConstants.SessionName);
_session.StopOnDispose = true;
#region Documentation
/*****************************************************
* BY DEFAULT ETW SESSIONS SURVIVE THE DEATH OF
* THE PROESS THAT CREATES THEM!
*
* Unlike most other resources on the system,
* ETW session live beyond the lifetime of the process
* that created them.
* This is very useful in some scenarios, but also
* creates the very real possibility of leaving
* 'orphan' sessions running.
*
* To help avoid this by default TraceEventSession
* sets 'StopOnDispose' so that it will stop
* the ETW session if the TraceEventSession dies.
* Thus executions that 'clean up' the TraceEventSession
* will clean up the ETW session.
* This covers many cases (including throwing exceptions)
*
* However if the process is killed manually (including control C)
* this cleanup will not happen.
*
* Thus best practices include
* * Add a Control C handler that calls session.Dispose()
* so it gets cleaned up in this common case
* * use the same session name (say your program name)
* run-to-run so you don't create many orphans.
*
* By default TraceEventSessions are in 'create'
* mode where it assumes you want to create a new session.
* In this mode if a session already exists,
* it is stopped and the new one is created.
*
* Here we install the Control C handler.
* It is OK if Dispose is called more than once.
*****************************************************/
#endregion // Documentation
Console.CancelKeyPress += (sender, e) => _session.Dispose();
#region UnhandledEvents
_session.Source.UnhandledEvents += (TraceEvent data) =>
{
if ((int)data.ID != 0xFFFE) // The EventSource manifest events show up as unhanded, filter them out.
Log(LogLevel.Warning, $"Unhandled {data.ToString()}", null);
};
#endregion // UnhandledEvents
#region _session.EnableProvider(...)
#region Documentation
/*****************************************************
* At this point we have created a TraceEventSession,
* hooked it up to a TraceEventSource, and hooked the
* TraceEventSource to a TraceEventParser
* (you can do several of these), and then hooked up callbacks
* up to the TraceEventParser (again you can have several).
* However we have NOT actually told any
* provider (EventSources) to actually send any events
* to our TraceEventSession.
* We do that now.
* Enable my provider, you can call many of these
* on the same session to get events from other providers.
* Because this EventSource did not define any keywords,
* I can only turn on all events or none.
* var restarted = session.EnableProvider(ETW_PROVIDER_NAME);
*****************************************************/
#endregion // Documentation
var restarted = _session.EnableProvider(
VisualRxEventSource.ProviderGuid,
TraceEventLevel.Always);
#region Validation
if (restarted) // Generally you don't bother with this warning.
{
Log(LogLevel.Warning,
$@"The session {EtwConstants.SessionName} was already active,
it has been restarted.", null);
}
#endregion // Validation
#endregion // _session.EnableProvider(...)
#region IObservable<TraceEvent> sending = ...
IObservable<TraceEvent> sending =
_session.Source.Dynamic.Observe(
VisualRxEventSource.ProviderName,
nameof(VisualRxEventSource.Send));
sending.Select(m =>
{
var json = m.FormattedMessage;
var marble = JsonConvert.DeserializeObject<Marble>(json, _setting);
return marble;
})
.Subscribe(_subject);
#endregion // IObservable<TraceEvent> sending = ...
// cancel the session
ct.Register(() => _session.Source.Dispose());
// go into a loop processing events can calling the callbacks.
// Because this is live data (not from a file)
// processing never completes by itself,
// but only because someone called 'source.Dispose()'.
Task t = Task.Factory.StartNew(() =>
{
try
{
_session.Source.Process();
}
catch (ThreadAbortException) { }
Log(LogLevel.Information, $"Session [{EtwConstants.SessionName}] Stopped.", null);
}, TaskCreationOptions.LongRunning);
await Task.Delay(10); // make sure that session.Source.Process() is listening (avoid racing)
}
public static void Run()
{
Out.WriteLine("******************** ObserveGCEvents DEMO ********************");
Out.WriteLine("This program Demos using the reactive framework (IObservable) to monitor");
Out.WriteLine(".NET Garbage collector (GC) events.");
Out.WriteLine();
Out.WriteLine("The program will print a line every time 100K of memory was allocated");
Out.WriteLine("on the GC heap along with the type of the object that 'tripped' the 100K");
Out.WriteLine("sample. It will also print a line every time a GC happened and show ");
Out.WriteLine("the sizes of each generation after the GC.");
Out.WriteLine();
Out.WriteLine("Run a .NET Program while the monitoring is active to see GC events.");
Out.WriteLine();
if (TraceEventSession.IsElevated() != true)
{
Out.WriteLine("Must be elevated (Admin) to run this method.");
Debugger.Break();
return;
}
var monitoringTimeSec = 10;
Out.WriteLine("The monitor will run for a maximum of {0} seconds", monitoringTimeSec);
Out.WriteLine("Press Ctrl-C to stop monitoring of GC Allocs");
// create a real time user mode session
using (var userSession = new TraceEventSession("ObserveGCAllocs"))
{
// Set up Ctrl-C to stop the session
SetupCtrlCHandler(() => { userSession.Stop(); });
// enable the CLR provider with default keywords (minus the rundown CLR events)
userSession.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose,
(ulong)(ClrTraceEventParser.Keywords.GC));
// Create a stream of GC Allocation events (happens every time 100K of allocations happen)
IObservable<GCAllocationTickTraceData> gcAllocStream = userSession.Source.Clr.Observe<GCAllocationTickTraceData>();
// Print the outgoing stream to the console
gcAllocStream.Subscribe(allocData =>
Out.WriteLine("GC Alloc : Proc: {0,10} Amount: {1,6:f1}K TypeSample: {2}", GetProcessName(allocData.ProcessID), allocData.AllocationAmount / 1000.0, allocData.TypeName));
// Create a stream of GC Collection events
IObservable<GCHeapStatsTraceData> gcCollectStream = userSession.Source.Clr.Observe<GCHeapStatsTraceData>();
// Print the outgoing stream to the console
gcCollectStream.Subscribe(collectData =>
Out.WriteLine("GC Collect: Proc: {0,10} Gen0: {1,6:f1}M Gen1: {2,6:f1}M Gen2: {3,6:f1}M LargeObj: {4,6:f1}M",
GetProcessName(collectData.ProcessID),
collectData.GenerationSize0 / 1000000.0,
collectData.GenerationSize1 / 1000000.0,
collectData.GenerationSize2 / 1000000.0,
collectData.GenerationSize3 / 1000000.0));
IObservable<long> timer = Observable.Timer(new TimeSpan(0, 0, monitoringTimeSec));
timer.Subscribe(delegate
{
Out.WriteLine("Stopped after {0} sec", monitoringTimeSec);
userSession.Dispose();
});
// OK we are all set up, time to listen for events and pass them to the observers.
userSession.Source.Process();
}
Out.WriteLine("Done with program.");
}
public void EnableProvider(TraceEventSession session)
{
session.EnableProvider(IISLogTraceEventParser.ProviderName);
}
/// <summary>
/// CollectData doe will turn on logging of data from 'eventSourceName' to the file 'dataFileName'.
/// It will then call EventGenerator.CreateEvents and wait 12 seconds for it to generate some data.
/// </summary>
static void CollectData(string eventSourceName, string dataFileName)
{
// Today you have to be Admin to turn on ETW events (anyone can write ETW events).
if (!(TraceEventSession.IsElevated() ?? false))
{
Out.WriteLine("To turn on ETW events you need to be Administrator, please run from an Admin process.");
Debugger.Break();
return;
}
// As mentioned below, sessions can outlive the process that created them. Thus you need a way of
// naming the session so that you can 'reconnect' to it from another process. This is what the name
// is for. It can be anything, but it should be descriptive and unique. If you expect multiple versions
// of your program to run simultaneously, you need to generate unique names (e.g. add a process ID suffix)
// however this is dangerous because you can leave data collection on if the program ends unexpectedly.
//
// In this case we tell the session to place the data in MonitorToFileData.etl.
var sessionName = "SimpleTraceLogSession";
Out.WriteLine("Creating a '{0}' session writing to {1}", sessionName, dataFileName);
Out.WriteLine("Use 'logman query -ets' to see active sessions.");
Out.WriteLine("Use 'logman stop {0} -ets' to manually stop orphans.", sessionName);
using (var session = new TraceEventSession(sessionName, dataFileName)) // Since we give it a file name, the data goes there.
using (var kernelSession = new TraceEventSession(KernelTraceEventParser.KernelSessionName, Path.ChangeExtension(dataFileName, ".kernel.etl")))
{
/* BY DEFAULT ETW SESSIONS SURVIVE THE DEATH OF THE PROESS THAT CREATES THEM! */
// Unlike most other resources on the system, ETW session live beyond the lifetime of the
// process that created them. This is very useful in some scenarios, but also creates the
// very real possibility of leaving 'orphan' sessions running.
//
// To help avoid this by default TraceEventSession sets 'StopOnDispose' so that it will stop
// the ETW session if the TraceEventSession dies. Thus executions that 'clean up' the TraceEventSession
// will clean up the ETW session. This covers many cases (including throwing exceptions)
//
// However if the process is killed manually (including control C) this cleanup will not happen.
// Thus best practices include
//
// * Add a Control C handler that calls session.Dispose() so it gets cleaned up in this common case
// * use the same session name run-to-run so you don't create many orphans.
//
// By default TraceEventSessions are in 'create' mode where it assumes you want to create a new session.
// In this mode if a session already exists, it is stopped and the new one is created.
//
// Here we install the Control C handler. It is OK if Dispose is called more than once.
Console.CancelKeyPress += delegate(object sender, ConsoleCancelEventArgs e) { session.Dispose(); kernelSession.Dispose(); };
// Enable kernel events.
kernelSession.EnableKernelProvider(KernelTraceEventParser.Keywords.ImageLoad | KernelTraceEventParser.Keywords.Process | KernelTraceEventParser.Keywords.Thread);
// Enable my provider, you can call many of these on the same session to get events from other providers
// Turn on the eventSource given its name.
// Note we turn on Verbose level all keywords (ulong.MaxValue == 0xFFF....) and turn on stacks for
// this provider (for all events, until Windows 8.1 you can only turn on stacks for every event
// for a particular provider or no stacks)
var options = new TraceEventProviderOptions() { StacksEnabled = true };
var restarted = session.EnableProvider(eventSourceName, TraceEventLevel.Verbose, ulong.MaxValue, options);
if (restarted) // Generally you don't bother with this warning, but for the demo we do.
Out.WriteLine("The session {0} was already active, it has been restarted.", sessionName);
// We also turn on CLR events because we need them to decode Stacks and we also get exception events (and their stacks)
session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)ClrTraceEventParser.Keywords.Default);
// Start another thread that Causes MyEventSource to create some events
// Normally this code as well as the EventSource itself would be in a different process.
EventGenerator.CreateEvents();
// Also generate some exceptions so we have interesting stacks to look at
Thread.Sleep(100);
EventGenerator.GenerateExceptions();
Out.WriteLine("Waiting 12 seconds for events to come in.");
Thread.Sleep(12000);
// Because the process in question (this process) lives both before and after the time the events were
// collected, we don't have complete information about JIT compiled methods in that method. There are
// some methods that were JIT compiled before the session started (e.g. SimpleTraceLog.Main) for which
// we do not have information. We collect this by forcing a CLR 'rundown' which will dump method information
// for JIT compiled methods that were not present. If you know that the process of interest ends before
// data collection ended or that data collection started before the process started, then this is not needed.
Out.WriteLine("Forcing rundown of JIT methods.");
var rundownFileName = Path.ChangeExtension(dataFileName, ".clrRundown.etl");
using (var rundownSession = new TraceEventSession(sessionName + "Rundown", rundownFileName))
{
rundownSession.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)ClrRundownTraceEventParser.Keywords.Default);
// Poll until 2 second goes by without growth.
for (var prevLength = new FileInfo(rundownFileName).Length; ; )
{
Thread.Sleep(2000);
var newLength = new FileInfo(rundownFileName).Length;
if (newLength == prevLength) break;
prevLength = newLength;
}
}
Out.WriteLine("Done with rundown.");
}
Out.WriteLine("Merging the raw files into a single '{0}' file.", dataFileName);
TraceEventSession.MergeInPlace(dataFileName, Out);
Out.WriteLine("Merge complete.");
}
public static void Run()
{
int monitoringTimeSec = 10;
if (Environment.OSVersion.Version.Major * 10 + Environment.OSVersion.Version.Minor < 62)
{
Out.WriteLine("This demo only works on Win8 / Win 2012 an above)");
return;
}
// Today you have to be Admin to turn on ETW events (anyone can write ETW events).
if (!(TraceEventSession.IsElevated() ?? false))
{
Out.WriteLine("To turn on ETW events you need to be Administrator, please run from an Admin process.");
Debugger.Break();
return;
}
string outputFileName = "ReloggerMonitorOutput.etl";
if (File.Exists(outputFileName))
File.Delete(outputFileName);
Out.WriteLine("******************** Simple Relogger DEMO ********************");
Out.WriteLine("This program shows how you can monitor an ETW stream in real time.");
Out.WriteLine("And conditionally pass the events on to a ETL file");
Out.WriteLine("Ctrl-C will end earlier");
Out.WriteLine();
Out.WriteLine("Please run some managed code while collection is happening...");
Out.WriteLine();
// To listen to ETW events you need a session, which allows you to control which events will be produced
// Note that it is the session and not the source that buffers events, and by default sessions will buffer
// 64MB of events before dropping events. Thus even if you don't immediately connect up the source and
// read the events you should not lose them.
//
// As mentioned below, sessions can outlive the process that created them. Thus you may need a way of
// naming the session so that you can 'reconnect' to it from another process. This is what the name
// is for. It can be anything, but it should be descriptive and unique. If you expect multiple versions
// of your program to run simultaneously, you need to generate unique names (e.g. add a process ID suffix)
// however this is dangerous because you can leave data collection on if the program ends unexpectedly.
var sessionName = "SimpleMontitorSession";
Out.WriteLine("Creating a '{0}' session", sessionName);
using (var session = new TraceEventSession(sessionName))
{
// Enable the events we care about for the kernel in the kernel session
// For this instant the session will buffer any incoming events.
// This has to be first, and it will fail if you are not on Win8.
session.EnableKernelProvider(
KernelTraceEventParser.Keywords.ImageLoad |
KernelTraceEventParser.Keywords.Process |
KernelTraceEventParser.Keywords.Thread);
// A relogger is a TraceEventSource and acts much like an ETWTraceEventSource, with extra Write APIS.
// Thus you get a callback on any event you want.
// Only things that you call 'WriteEvent' on will end up in the output file.
var relogger = new ETWReloggerTraceEventSource(sessionName, TraceEventSourceType.Session, outputFileName);
// Here we set up the callbacks we want in the output file. In this case all GC allocation Tick
// events for 'String' as well as any ExceptionStart events.
relogger.Clr.GCAllocationTick += delegate(GCAllocationTickTraceData data)
{
if (data.TypeName == "System.String")
relogger.WriteEvent(data);
};
relogger.Clr.ExceptionStart += delegate(ExceptionTraceData data)
{
relogger.WriteEvent(data);
};
// We also keep the image load events for DLL with 'clr' in their name.
relogger.Kernel.ImageGroup += delegate(ImageLoadTraceData data)
{
if (0 <= data.FileName.IndexOf("clr", StringComparison.OrdinalIgnoreCase))
relogger.WriteEvent(data);
};
#if false // Turn on to get debugging on unhandled events.
relogger.UnhandledEvents += delegate(TraceEvent data)
{
Console.WriteLine("Unknown Event " + data);
};
#endif
// Allow the test to be terminated with Ctrl-C cleanly.
Console.CancelKeyPress += delegate(object sender, ConsoleCancelEventArgs e) { session.Dispose(); };
// Set up a timer to stop processing after monitoringTimeSec
var timer = new Timer(delegate(object state)
{
Out.WriteLine("Stopped after {0} sec", monitoringTimeSec);
session.Dispose();
}, null, monitoringTimeSec * 1000, Timeout.Infinite);
// Turn on the events to the provider. In this case most CLR events
Out.WriteLine("**** Turn on CLR Etw Providers. Run managed code to see events.");
session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)ClrTraceEventParser.Keywords.Default);
// go into a loop processing events can calling the callbacks. Because this is live data (not from a file)
// processing never completes by itself, but only because someone called 'source.Dispose()'.
Out.WriteLine("**** Start listening for events from the Microsoft-Demos-SimpleMonitor provider.");
Out.WriteLine("The monitor will run for a maximum of {0} seconds. Run managed code for more output.", monitoringTimeSec);
relogger.Process();
Out.WriteLine();
Out.WriteLine("Stopping the collection of events.");
timer.Dispose(); // Turn off the timer.
}
Out.WriteLine("Monitoring complete, only certain CLR events put in the output file.");
Out.WriteLine("The output ETL file: {0}", Path.GetFullPath(outputFileName));
Out.WriteLine();
if (!File.Exists(outputFileName))
{
Out.WriteLine("Error: No output file was generated (did you run anything during the collection?");
return;
}
// Show what was actually produced in the filtered file.
DataProcessing(outputFileName);
}
/// <summary>
/// This is a demo of using TraceEvent to activate a 'real time' provider that is listening to
/// the MyEventSource above. Normally this event source would be in a different process, but
/// it also works if this process generate the events and I do that here for simplicity.
/// </summary>
public static int Run()
{
Out.WriteLine("******************** SimpleEventSourceMonitor DEMO ********************");
Out.WriteLine("This program generates processes and displays EventSource events");
Out.WriteLine("using the ETW REAL TIME pipeline. (thus no files are created)");
Out.WriteLine();
// Today you have to be Admin to turn on ETW events (anyone can write ETW events).
if (!(TraceEventSession.IsElevated() ?? false))
{
Out.WriteLine("To turn on ETW events you need to be Administrator, please run from an Admin process.");
Debugger.Break();
return -1;
}
// To listen to ETW events you need a session, which allows you to control which events will be produced
// Note that it is the session and not the source that buffers events, and by default sessions will buffer
// 64MB of events before dropping events. Thus even if you don't immediately connect up the source and
// read the events you should not lose them.
//
// As mentioned below, sessions can outlive the process that created them. Thus you may need a way of
// naming the session so that you can 'reconnect' to it from another process. This is what the name
// is for. It can be anything, but it should be descriptive and unique. If you expect multiple versions
// of your program to run simultaneously, you need to generate unique names (e.g. add a process ID suffix)
// however this is dangerous because you can leave data collection on if the program ends unexpectedly.
var sessionName = "SimpleMontitorSession";
Out.WriteLine("Creating a '{0}' session", sessionName);
Out.WriteLine("Use 'logman query -ets' to see active sessions.");
Out.WriteLine("Use 'logman stop {0} -ets' to manually stop orphans.", sessionName);
using (var session = new TraceEventSession(sessionName))
{
/* BY DEFAULT ETW SESSIONS SURVIVE THE DEATH OF THE PROESS THAT CREATES THEM! */
// Unlike most other resources on the system, ETW session live beyond the lifetime of the
// process that created them. This is very useful in some scenarios, but also creates the
// very real possibility of leaving 'orphan' sessions running.
//
// To help avoid this by default TraceEventSession sets 'StopOnDispose' so that it will stop
// the ETW session if the TraceEventSession dies. Thus executions that 'clean up' the TraceEventSession
// will clean up the ETW session. This covers many cases (including throwing exceptions)
//
// However if the process is killed manually (including control C) this cleanup will not happen.
// Thus best practices include
//
// * Add a Control C handler that calls session.Dispose() so it gets cleaned up in this common case
// * use the same session name (say your program name) run-to-run so you don't create many orphans.
//
// By default TraceEventSessions are in 'create' mode where it assumes you want to create a new session.
// In this mode if a session already exists, it is stopped and the new one is created.
//
// Here we install the Control C handler. It is OK if Dispose is called more than once.
Console.CancelKeyPress += delegate(object sender, ConsoleCancelEventArgs e) { session.Dispose(); };
// 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.
session.Source.Dynamic.All += delegate(TraceEvent data)
{
// ETW buffers events and only delivers them after buffering up for some amount of time. Thus
// there is a small delay of about 2-4 seconds between the timestamp on the event (which is very
// accurate), and the time we actually get the event. We measure that delay here.
var delay = (DateTime.Now - data.TimeStamp).TotalSeconds;
Out.WriteLine("GOT Event Delay={0:f1}sec: {1} ", delay, data.ToString());
};
// Add logic on what to do when we get "MyFirstEvent"
session.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"
session.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"
session.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, this will 'Process() to return. It is OK to call Dispose twice
session.Source.Dispose();
});
#if DEBUG
// The callback above will only be called for events the parser recognizes (in the case of DynamicTraceEventParser, EventSources)
// 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.
session.Source.UnhandledEvents += delegate(TraceEvent data)
{
if ((int)data.ID != 0xFFFE) // The EventSource manifest events show up as unhanded, filter them out.
Out.WriteLine("GOT UNHANDLED EVENT: " + data.Dump());
};
#endif
// At this point we have created a TraceEventSession, hooked it up to a TraceEventSource, and hooked the
// TraceEventSource to a TraceEventParser (you can do several of these), and then hooked up callbacks
// up to the TraceEventParser (again you can have several). However we have NOT actually told any
// provider (EventSources) to actually send any events to our TraceEventSession.
// We do that now.
// Enable my provider, you can call many of these on the same session to get events from other providers.
// Because this EventSource did not define any keywords, I can only turn on all events or none.
var restarted = session.EnableProvider("Microsoft-Demos-SimpleMonitor");
if (restarted) // Generally you don't bother with this warning, but for the demo we do.
Out.WriteLine("The session {0} was already active, it has been restarted.", sessionName);
// Start another thread that Causes MyEventSource to create some events
// Normally this code as well as the EventSource itself would be in a different process.
EventGenerator.CreateEvents();
Out.WriteLine("**** Start listening for events from the Microsoft-Demos-SimpleMonitor provider.");
// go into a loop processing events can calling the callbacks. Because this is live data (not from a file)
// processing never completes by itself, but only because someone called 'source.Dispose()'.
session.Source.Process();
Out.WriteLine();
Out.WriteLine("Stopping the collection of events.");
}
return 0;
}
public static void Run()
{
Out.WriteLine("******************** ObserveEventSource DEMO ********************");
Out.WriteLine("This program Demos using the reactive framework (IObservable) to monitor");
Out.WriteLine("EventSource events in real time, parsing their payloads dynamically.");
Out.WriteLine();
Out.WriteLine("The program has an EventSource that generates two kinds of events for 10 secs.");
Out.WriteLine("while another part of the program reads them using IObservables and prints");
Out.WriteLine("their parsed payload values. ");
Out.WriteLine();
if (TraceEventSession.IsElevated() != true)
{
Out.WriteLine("Must be elevated (Admin) to run this method.");
Debugger.Break();
return;
}
var monitoringTimeSec = 15;
Out.WriteLine("The monitor will run for a maximum of {0} seconds", monitoringTimeSec);
Out.WriteLine("Press Ctrl-C to stop monitoring.");
// create a real time user mode session
using (var userSession = new TraceEventSession("ObserveEventSource"))
{
// Set up Ctrl-C to stop both user mode and kernel mode sessions
SetupCtrlCHandler(() => { if (userSession != null) userSession.Stop(); });
// Turn on the Microsoft-Demos-SimpleMonitor provider
userSession.EnableProvider("Microsoft-Demos-SimpleMonitor");
// Create a stream of the 'MyFirstEvent' event source events and print their payloads
IObservable<TraceEvent> firstEventStream = userSession.Source.Dynamic.Observe("Microsoft-Demos-SimpleMonitor", "MyFirstEvent");
firstEventStream.Subscribe(onNext: ev => Out.WriteLine("FIRST_EVENTS : MyName: '{0}' MyId: {1}", ev.PayloadByName("MyName"), ev.PayloadByName("MyId")));
// Create a stream of the 'MySecond'Event' event source events and print their payloads
IObservable<TraceEvent> secondEventStream = userSession.Source.Dynamic.Observe("Microsoft-Demos-SimpleMonitor", "MySecondEvent");
secondEventStream.Subscribe(onNext: ev => Out.WriteLine("SECOND_EVENTS : MyId: {0}", ev.PayloadByName("MyId")));
// For debugging purposes, print every event from the SimpleMonitor stream
IObservable<TraceEvent> allEventStream = userSession.Source.Dynamic.Observe(null);
allEventStream.Subscribe(onNext: ev => Out.WriteLine("FROM_EVENTSOURCE: {0}/{1} ", ev.ProviderName, ev.EventName));
// It is also useful for debugging purposes to see any events that entered by were not handled by any parser. These can be bugs.
IObservable<TraceEvent> unhandledEventStream = userSession.Source.ObserveUnhandled();
unhandledEventStream.Subscribe(onNext: ev => Out.WriteLine("UNHANDLED : {0}/{1} ", ev.ProviderName, ev.EventName));
// Start Generate some events so we have something to see
Producer.EventGenerator.CreateEvents();
// Set up a timer to stop processing after monitoringTimeSec
IObservable<long> timer = Observable.Timer(new TimeSpan(0, 0, monitoringTimeSec));
timer.Subscribe(delegate
{
Out.WriteLine("Stopped after {0} sec", monitoringTimeSec);
userSession.Dispose();
});
// OK we are all set up, time to listen for events and pass them to the observers.
userSession.Source.Process();
}
Out.WriteLine("Done with program.");
}