static void Main(string[] args) { Out = Console.Out; Out.WriteLine("Hello World!"); using (var session = new TraceEventSession("pri")) { void ConsoleOnCancelKeyPress(object sender, ConsoleCancelEventArgs e) { Console.CancelKeyPress -= ConsoleOnCancelKeyPress; session?.Dispose(); } Console.CancelKeyPress += ConsoleOnCancelKeyPress; session.EnableKernelProvider(KernelTraceEventParser.Keywords.Registry); session.Source.Kernel.RegistryCreate += KernelParser_RegistryCreate; session.Source.Kernel.RegistrySetValue += KernelParser_RegistrySetValue; session.Source.Kernel.RegistryDeleteValue += KernelParser_RegistryDeleteValue; session.Source.Kernel.RegistryDelete += KernelParser_RegistryDelete; session.Source.Kernel.RegistryKCBCreate += KernelParser_RegistryKCBCreate; session.Source.Kernel.RegistryKCBDelete += KernelParser_RegistryKCBDelete; session.Source.Kernel.RegistryKCBRundownBegin += Kernel_RegistryKCBRundownBegin; session.Source.Kernel.RegistryKCBRundownEnd += Kernel_RegistryKCBRundownEnd; Out.WriteLine("Collecting events"); session.Source.Process(); Out.WriteLine("Stopping collection of events"); } }
private void Dispose(bool disposing) { if (disposing) { // session.StopOnDispose = true; //default // By calling dispose the session will stop. // this is the way to stop the realtime session // in a timely manner output("disposing of etw wacher"); session?.Dispose(); } }
public void Stop() { using (var rundownSession = new TraceEventSession(sessionName + "Rundown", "data.clrRundown.etl")) { rundownSession.EnableProvider(ClrRundownTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)ClrRundownTraceEventParser.Keywords.Default); // Poll until 2 second goes by without growth. for (var prevLength = new FileInfo("data.clrRundown.etl").Length;;) { Thread.Sleep(2000); var newLength = new FileInfo("data.clrRundown.etl").Length; if (newLength == prevLength) { break; } prevLength = newLength; } } // TODO: Currenty not aware of any more sophisticated control, when hosting sub-process it will wait for timeout without new events after sub-process ends //Thread.Sleep(4000); stopped = true; session?.Dispose(); kernelSession?.Dispose(); TraceEventSession.MergeInPlace("data.etl", TextWriter.Null); //var traceLog = TraceLog.OpenOrConvert("data.etl"); //var simpleTraceLogProcess = traceLog.Processes.LastProcessWithID(Process.GetCurrentProcess().Id); //foreach (var data in simpleTraceLogProcess.EventsInProcess) //{ //} using (var source = new ETWTraceEventSource("data.etl")) { source.Clr.GCHeapStats += ClrOnGcHeapStats; source.Clr.GCStart += ClrOnGcStart; source.Clr.GCStop += ClrOnGcStop; source.Clr.GCGenerationRange += ClrOnGcGenerationRange; source.Process(); } }
/// <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", "MyStopEvent", 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 void Dispose() { m_EtwSession?.Dispose(); }
void IDisposable.Dispose() { m_session?.Dispose(); m_session = null; m_cts.Dispose(); }
public void CreateETWLogger() { const string config = @" <loggers> <log name=""etwLogger"" type=""etl""> <source name=""Microsoft-Diagnostics-Tracing-Logging"" /> </log> </loggers>"; LogManager.AllowEtwLogging = AllowEtwLoggingValues.Enabled; LogManager.Start(); Assert.IsTrue(LogManager.SetConfiguration(config)); Assert.AreEqual(1, LogManager.singleton.fileLoggers.Count); var theLogger = LogManager.GetFileLogger("etwLogger") as ETLFileLogger; Assert.IsNotNull(theLogger); string filename = Path.GetFileName(theLogger.Filename); Assert.AreEqual(filename, "etwLogger.etl"); var session = new TraceEventSession(ETLFileLogger.SessionPrefix + "etwLogger", TraceEventSessionOptions.Attach); Assert.IsNotNull(session); Assert.AreEqual(LogManager.DefaultFileBufferSizeMB, session.BufferSizeMB); session.Dispose(); LogManager.Shutdown(); }
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> /// 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 override void Finished() { session?.Dispose(); all.Remove(this); }
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."); }
static void Main(string[] args) { _session = new TraceEventSession("exceptionTrace"); _session.EnableProvider(ClrTraceEventParser.ProviderGuid); _session.Source.Clr.ExceptionStart += OnClrOnExceptionStart; _handlerTask = Task.Run(() => _session.Source.Process()); while (true) { var keyInfo = Console.ReadKey(true); switch (keyInfo.KeyChar) { case '?': Console.WriteLine("q - quit, p - prcess, e - exception, f - filter (F-clear, Alt-f - print), d - data, ' ' - pause (buffered)"); break; case ' ': if (_outputEnabled) { Disable(); } else { Enable(); } break; case 'q': goto exit; case 'p': _printOptions.ProcessInfo = _printOptions.EnumRotate(_printOptions.ProcessInfo); break; case 'e': _printOptions.ExceptionInfo = _printOptions.EnumRotate(_printOptions.ExceptionInfo); break; case 'd': _printOptions.DataPrint = !_printOptions.DataPrint; break; case 'F': _printOptions.SimpleFilter.Clear(); break; case 'f': if ((keyInfo.Modifiers & ConsoleModifiers.Alt) != 0) { Console.WriteLine(string.Join(Environment.NewLine, _printOptions.SimpleFilter)); break; } Disable(); Console.Write("Enter filter:"); var filter = Console.ReadLine(); if (string.IsNullOrWhiteSpace(filter)) { break; } filter = filter.Trim(); _printOptions.SimpleFilter.Add(filter); Enable(); break; } } exit: _session.Stop(); _handlerTask.Wait(); _session?.Dispose(); }
private int StartListen() { // This is the name of the event source. var providerName = textBox1.Text; //Debug.Assert(providerName == MyEventSource.Log.Name); // Given just the name of the eventSource you can get the GUID for the evenSource by calling this API. // From a ETW perspective, the GUID is the 'true name' of the EventSource. //var providerGuid = TraceEventSession.GetEventSourceGuidFromName(providerName); //Debug.Assert(providerGuid == MyEventSource.Log.Guid); // Today you have to be Admin to turn on ETW events (anyone can write ETW events). if (!(TraceEventSession.IsElevated() ?? false)) { Console.WriteLine("To turn on ETW events you need to be Administrator, please run from an Admin process."); return(-1); } // 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 mulitple versions // of your program to run simultaneously, you need to generate unique names (e.g. add a process ID suffix) Console.WriteLine("Creating a 'My Session' session"); var sessionName = "My Session"; using (var session = new TraceEventSession(sessionName, null)) // the null second parameter means 'real time session' { // Note that sessions create a OS object (a session) that lives beyond the lifetime of the process // that created it (like Filles), thus you have to be more careful about always cleaning them up. // An importanty 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. session.StopOnDispose = true; // By default, if you hit Ctrl-C your .NET objects may not be disposed, so force it to. It is OK if dispose is called twice. Console.CancelKeyPress += delegate(object sender, ConsoleCancelEventArgs e) { session.Dispose(); }; // prepare to read from the session, connect the ETWTraceEventSource to the session using (var source = new ETWTraceEventSource(sessionName, TraceEventSourceType.Session)) { // To demonstrate non-trivial event manipuation, we calculate the time delta between 'MyFirstEvent and 'MySecondEvent' // These variables are used in this calculation int lastMyEventID = int.MinValue; // an illegal value to start with. double lastMyEventMSec = 0; // Hook up the parser that knows about EventSources var parser = new DynamicTraceEventParser(source); parser.All += delegate(TraceEvent data) { Console.WriteLine("GOT EVENT: " + data.ToString()); //if (data.ProviderGuid == providerGuid) // We don't actually need this since we only turned one one provider. //{ // Note that this is the inefficient way of parsing events (there are string comparisions on the // event Name and every payload value), however it is fine for events that occur less than 100 times // a second. For more volumous events, you should consider making a parser for you eventSource // (covered in another demo). This makes your code fare less 'reflection-like' where you have lots // of strings (e.g. "MyFirstEvent", "MyId" ...) which is better even ignoring the performance benefit. if (data.EventName == "MyFirstEvent") { // On First Events, simply remember the ID and time of the event lastMyEventID = (int)data.PayloadByName("MyId"); lastMyEventMSec = data.TimeStampRelativeMSec; } else if (data.EventName == "MySecondEvent") { // On Second Events, if the ID matches, compute the delta and display it. if (lastMyEventID == (int)data.PayloadByName("MyId")) { Console.WriteLine(" > Time Delta from first Event = {0:f3} MSec", data.TimeStampRelativeMSec - lastMyEventMSec); } } else if (data.EventName == "Stop") { // Stop processing after we we see the 'Stop' event //source.DisposeClose(); } //} }; // Enable my provider, you can call many of these on the same session to get other events. session.EnableProvider(providerName, TraceEventLevel.Always); // 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. Console.WriteLine("Staring Listing for events"); // 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.Close()'. source.Process(); Console.WriteLine(); Console.WriteLine("Stopping the collection of events."); } } return(0); }
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."); }
protected override void OnTerminate() { Session?.Source.Dispose(); Session?.Dispose(); }
/// <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 CloseDuplicateTraceSession(string sessionName) { InternalLogger.Write.ConflictingTraceSessionFound(sessionName); TraceEventSession s = null; try { // we can't control this session so we need to stop it s = new TraceEventSession(sessionName); // might throw if it's in the midst of being shut down s.Stop(); } catch (FileNotFoundException) { // well, okay, then it's probably gone now. } finally { if (s != null) { s.Dispose(); } } // Now we enter a brief waiting period to make sure it dies. We must do this because ControlTrace() // (the underlying win32 API) is asynchronous and our request to terminate the session may take // a small amount of time to complete. if (!WaitForSessionChange(sessionName, false)) { InternalLogger.Write.ConflictingTraceSessionStuck(sessionName); throw new OperationCanceledException("could not tear down existing trace session"); } }
public void Dispose() { _etwSession?.Dispose(); }
/// <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 void Dispose() { Console.WriteLine("Disposing resources"); _session?.Dispose(); _timer?.Dispose(); }
public static void Run() { var monitoringTimeSec = 10; Out.WriteLine("******************** ModuleLoadMonitor DEMO ********************"); Out.WriteLine("Monitoring DLL Loads and Process Starts/Stops system wide"); 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 program to see some events!"); Out.WriteLine(); if (TraceEventSession.IsElevated() != true) { Out.WriteLine("Must be elevated (Admin) to run this program."); Debugger.Break(); return; } // Start the session as a real time monitoring session, // Before windows 8, there is a restriction that if you wanted kernel events you must name your session // 'NT Kernel Logger' (the value of KernelSessionName) and there can only be one such session and no // other ETW providers can be enabled for that session (thus you need two sessions if you want both // kernel and non-kernel events (fixed in Win 8). We want this to work on Win 7 so we live with those // restrictions. using (TraceEventSession session = new TraceEventSession(KernelTraceEventParser.KernelSessionName)) { /* 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. Console.CancelKeyPress += new ConsoleCancelEventHandler((object sender, ConsoleCancelEventArgs cancelArgs) => { Out.WriteLine("Control C pressed"); // Note that if you hit Ctrl-C twice rapidly you may be called concurrently. session.Dispose(); // Note that this causes Process() to return. cancelArgs.Cancel = true; // This says don't abort, since Process() will return we can terminate nicely. }); // Enable the Kernel events that we want. At this point data is being collected (but being buffered since we are not reading it) // See KernelTraceEventParser.Keywords for what else can be turned on and KernelTraceEventParser for a description // of the events that you get when you turn on the various kernel keywords. Many kernel events will also log a stack // when they fire see EnableKernelProvider for more on that. session.EnableKernelProvider(KernelTraceEventParser.Keywords.ImageLoad | KernelTraceEventParser.Keywords.Process); // .Source will auto-create a TraceEventSource reading the data from the session // .Kernel will auto-create a KernelTraceEventParser getting its events from the source // .ImageLoad is an event that you can subscribe to that will be called back when Image load events happen (complete with parsed event) session.Source.Kernel.ImageLoad += delegate(ImageLoadTraceData data) { Out.WriteLine("Process {0,16} At 0x{1,8:x} Loaded {2}", data.ProcessName, data.ImageBase, data.FileName); }; // Subscribe to more events (process start) session.Source.Kernel.ProcessStart += delegate(ProcessTraceData data) { Out.WriteLine("Process Started {0,6} Parent {1,6} Name {2,8} Cmd: {3}", data.ProcessID, data.ParentID, data.ProcessName, data.CommandLine); }; // Subscribe to more events (process end) session.Source.Kernel.ProcessStop += delegate(ProcessTraceData data) { Out.WriteLine("Process Ending {0,6} ", data.ProcessID); }; // Set up a timer to stop processing after monitoringTimeSec var timer = new Timer(delegate(object state) { Out.WriteLine("Stopped after {0} sec", monitoringTimeSec); session.Source.StopProcessing(); }, null, monitoringTimeSec * 1000, Timeout.Infinite); // Start listening for events, will end if session.Source.StopProcessing() is called or session.Dispose() is called. // Here we never do either of these and thus will only stop when Ctrl-C is hit (but it will clean up because of // our control C handler). session.Source.Process(); timer.Dispose(); // Done with the timer. } Out.WriteLine("Stopping monitor"); }
public void Dispose() { session?.Dispose(); writer?.Dispose(); }
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 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."); }
/// <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 void Dispose() { _session?.Dispose(); _isFinished?.Dispose(); }
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")); }
public static void Stop() { tSession?.Dispose(); received = 0; }
/// <summary> /// Add the nodes of the .NET heap for the process 'processID' to 'memoryGraph' sending diagnostic /// messages to 'log'. If 'memoryGraph' is null, the ETW providers are triggered by we obviously /// don't update the memoryGraph. Thus it is only done for the side effect of triggering a .NET heap /// dump. returns true if successful. /// </summary> static public bool Dump(int processID, MemoryGraph memoryGraph, TextWriter log, DotNetHeapInfo dotNetInfo = null) { var sw = Stopwatch.StartNew(); var dumper = new DotNetHeapDumpGraphReader(log); dumper.DotNetHeapInfo = dotNetInfo; bool dumpComplete = false; bool listening = false; TraceEventSession session = null; Task readerTask = null; try { bool etwDataPresent = false; TimeSpan lastEtwUpdate = sw.Elapsed; // Set up a separate thread that will listen for ETW events coming back telling us we succeeded. readerTask = Task.Factory.StartNew(delegate { string sessionName = "PerfViewGCHeapSession"; session = new TraceEventSession(sessionName, null); int gcNum = -1; session.BufferSizeMB = 256; // Events come pretty fast, so make the buffer bigger. // Start the providers and trigger the GCs. log.WriteLine("{0,5:n1}s: Requesting a .NET Heap Dump", sw.Elapsed.TotalSeconds); // Have to turn on Kernel provider first (before touching Source) so we do it here. session.EnableKernelProvider(KernelTraceEventParser.Keywords.Process | KernelTraceEventParser.Keywords.ImageLoad); session.Source.Clr.GCStart += delegate(GCStartTraceData data) { if (data.ProcessID != processID) { return; } etwDataPresent = true; if (gcNum < 0 && data.Depth == 2 && data.Type != GCType.BackgroundGC) { gcNum = data.Count; log.WriteLine("{0,5:n1}s: Dot Net Dump Started...", sw.Elapsed.TotalSeconds); } }; session.Source.Clr.GCStop += delegate(GCEndTraceData data) { if (data.ProcessID != processID) { return; } if (data.Count == gcNum) { log.WriteLine("{0,5:n1}s: DotNet GC Complete.", sw.Elapsed.TotalSeconds); dumpComplete = true; } }; session.Source.Clr.GCBulkNode += delegate(GCBulkNodeTraceData data) { if (data.ProcessID != processID) { return; } etwDataPresent = true; if ((sw.Elapsed - lastEtwUpdate).TotalMilliseconds > 500) { log.WriteLine("{0,5:n1}s: Making GC Heap Progress...", sw.Elapsed.TotalSeconds); } lastEtwUpdate = sw.Elapsed; }; if (memoryGraph != null) { dumper.SetupCallbacks(memoryGraph, session.Source, processID.ToString()); } listening = true; session.Source.Process(); log.WriteLine("{0,5:n1}s: ETW Listener dieing", sw.Elapsed.TotalSeconds); }); // Wait for thread above to start listening (should be very fast) while (!listening) { readerTask.Wait(1); } Debug.Assert(session != null); // Request the heap dump. We try to isolate this to a single process. var options = new TraceEventProviderOptions() { ProcessIDFilter = new List <int>() { processID } }; // There is a bug in the runtime 4.6.2 and earlier where we only clear the table of types we have already emitted when you ENABLE // the Clr Provider WITHOUT the ClrTraceEventParser.Keywords.Type keyword. we achive this by turning on just the GC events, // (which clears the Type table) and then turn all the events we need on. session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Informational, (ulong)ClrTraceEventParser.Keywords.GC, options); System.Threading.Thread.Sleep(50); // Wait for it to complete (it is async) // 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.GCHeapSnapshot, options); // Project N support. session.EnableProvider(ClrTraceEventParser.NativeProviderGuid, TraceEventLevel.Informational, (ulong)ClrTraceEventParser.Keywords.GCHeapSnapshot, options); for (;;) { if (readerTask.Wait(100)) { break; } if (!etwDataPresent && sw.Elapsed.TotalSeconds > 5) // Assume it started within 5 seconds. { log.WriteLine("{0,5:n1}s: Assume no Dot Heap", sw.Elapsed.TotalSeconds); break; } if (sw.Elapsed.TotalSeconds > 100) // Time out after 100 seconds. { log.WriteLine("{0,5:n1}s: Timed out after 100 seconds", sw.Elapsed.TotalSeconds); break; } // TODO FIX NOW, time out faster if we seek to be stuck if (dumpComplete) { break; } } if (etwDataPresent) { dumper.ConvertHeapDataToGraph(); // Finish the conversion. } } finally { // Stop the ETW providers log.WriteLine("{0,5:n1}s: Shutting down ETW session", sw.Elapsed.TotalSeconds); if (session != null) { session.Dispose(); } } if (readerTask != null) { log.WriteLine("{0,5:n1}s: Waiting for shutdown to complete.", sw.Elapsed.TotalSeconds); if (!readerTask.Wait(2000)) { log.WriteLine("{0,5:n1}s: Shutdown wait timed out after 2 seconds.", sw.Elapsed.TotalSeconds); } } log.WriteLine("[{0,5:n1}s: Done Dumping .NET heap success={1}]", sw.Elapsed.TotalSeconds, dumpComplete); return(dumpComplete); }