/// <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."); }