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 Window_Closed(object sender, EventArgs e) { // Cleanup TraceSession and temp update files... TraceEventSession.GetActiveSession(SessionName)?.Stop(true); _backgroundWorker.Dispose(); if (_updateStarted) { return; } try { if (_updateTempFileName == null) { return; } if (!File.Exists(_updateTempFileName)) { File.Delete(_updateTempFileName); } } catch (Exception) { // ignored } }
private static string WriteTestFile(string logFilename) { LogManager.Start(); LogManager.SetConfiguration(null); LogManager.AllowEtwLogging = AllowEtwLoggingValues.Enabled; string fullFilename = Path.Combine(LogManager.DefaultDirectory, logFilename); try { File.Delete(fullFilename); } catch (DirectoryNotFoundException) { } string sessionName = Path.GetFileNameWithoutExtension(logFilename); IEventLogger logger = LogManager.CreateETWLogger(sessionName, "."); logger.SubscribeToEvents(TestLogger.Write.Guid, EventLevel.Verbose); while (TraceEventSession.GetActiveSession(ETLFileLogger.SessionPrefix + sessionName) == null) { // Ensure session starts... Thread.Sleep(100); } // Even after the session is listed it seemingly isn't "ready", periodic test failures seem to occur without // an enforced pause here. Thread.Sleep(100); WriteTestEvents(); LogManager.DestroyLogger(logger); LogManager.Shutdown(); Assert.IsTrue(File.Exists(fullFilename)); return(fullFilename); }
/// <summary> /// Creates a Task with no return value that hosts the event processing loop. Ensures the session is started /// prior to returning. /// </summary> /// <returns>A Task to handle the event processing.</returns> public Task CreateProcessingTask() { var task = new Task(this.Process); task.Start(); int waitTime = 5000; while (waitTime > 0 && TraceEventSession.GetActiveSession(this.sessionName) == null) { if (task.IsFaulted) { throw new OperationCanceledException("Unable to start realtime session.", task.Exception); } Thread.Sleep(100); waitTime -= 100; } if (TraceEventSession.GetActiveSession(this.sessionName) == null) { throw new OperationCanceledException("Unable to start realtime session."); } return(task); }
private string CleanupMatchingSessions(string sessionNamePrefix, bool keepOne) { string result = null; foreach (var sesName in TraceEventSession.GetActiveSessionNames()) { if (!sesName.StartsWith(sessionNamePrefix, StringComparison.OrdinalIgnoreCase)) { continue; } var session = TraceEventSession.GetActiveSession(sesName); if (session == null || !session.IsRealTime) { continue; } if (keepOne && result == null) { result = session.SessionName; } else { session.Dispose(); } } return(result); }
public void Start(int pid) { TraceEventSession.GetActiveSession("HeapSession")?.Dispose(); _session = new TraceEventSession("HeapSession"); _session.EnableWindowsHeapProvider(pid); _session.Source.Dynamic.All += Source_AllEvents; _session.Source.Kernel.StackWalkStack += Kernel_StackWalkStack; Task.Factory.StartNew(() => _session.Source.Process()); }
public static void ClearAllActiveObservableEventListenerSession() { var activeSessions = TraceEventSession.GetActiveSessionNames() .Where(x => x.StartsWith("ObservableEventListener")) .Select(x => TraceEventSession.GetActiveSession(x)); var activeCount = 0; foreach (var item in activeSessions) { item.Dispose(); activeCount++; } Console.WriteLine("Cleared ActiveSession's Count:" + activeCount); }
public void Cleanup() { try { // This clean up is there to clean up possible left over trace event sessions during the Debug of the unit tests. foreach (var name in TraceEventSession.GetActiveSessionNames().Where(n => n.StartsWith("ApplicationInsights-", StringComparison.Ordinal))) { TraceEventSession.GetActiveSession(name).Stop(); } } catch { // This should normally not happen. But if this happens, there's, unfortunately, nothing too much we can do here. } }
public WMIEventParser(TraceLogEventSource source, string autoLoggerSessionName, string autoLoggerFileName) { mySource = source; source.Kernel.ProcessStart += Kernel_ProcessStart; source.Kernel.ProcessStop += Kernel_ProcessStop; // stop already started autologger sessoin which runs since boot // this way we capture all WMI events even the ones which did happen while our service was already starting! // It can happen that we duplicate some events but that is still better than to loose important polling events // which can happen in services which run early in the boot phase. var fileSession = TraceEventSession.GetActiveSession(autoLoggerSessionName); fileSession?.Stop(); // Only parse when session was still running otherwise we would inject old events upon session restart again if (fileSession != null) { using WMIETlFileReader reader = new WMIETlFileReader(Environment.ExpandEnvironmentVariables(autoLoggerFileName)); myUnprocessedEvents = reader.GetPreviousStartEvents(); } }
public override void Process() { if (TraceEventSession.GetActiveSession(this.sessionName) != null) { if (!this.reclaimSession) { throw new OperationCanceledException("Session already exists with name " + this.sessionName); } ETLFileLogger.CloseDuplicateTraceSession(this.sessionName); } this.CurrentSessionName = this.sessionName; this.session = new TraceEventSession(this.sessionName, null); foreach (var subscription in this.enabledProviders) { Guid providerID = subscription.Item1; var minimumSeverity = (TraceEventLevel)subscription.Item2; ulong keywords = subscription.Item3; if (providerID == ClrTraceEventParser.ProviderGuid) { this.ProcessEventTypes |= EventTypes.Clr; } else if (providerID == KernelTraceEventParser.ProviderGuid) { this.ProcessEventTypes |= EventTypes.Kernel; } else { this.ProcessEventTypes |= EventTypes.EventSource; } this.session.EnableProvider(providerID, minimumSeverity, keywords); } // Ordering seems to matter here! If we create the source before there's something happening in the // session we end up with invalid timestamps and no events get emitted. Keep this here. this.TraceEventSource = new ETWTraceEventSource(this.sessionName, TraceEventSourceType.Session); this.ProcessEvents(); }
private string WriteTestFile(string logFilename) { LogManager.Start(); LogManager.SetConfiguration((Configuration)null); LogManager.Configuration.AllowEtwLogging = Configuration.AllowEtwLoggingValues.Enabled; string fullFilename = Path.Combine(LogManager.DefaultDirectory, logFilename); try { File.Delete(fullFilename); } catch (DirectoryNotFoundException) { } var sName = Path.GetFileNameWithoutExtension(logFilename); var subs = new[] { new EventProviderSubscription(TestLogger.Write.Guid, EventLevel.Verbose) }; var config = new LogConfiguration(sName, LogType.EventTracing, subs) { Directory = "." }; IEventLogger logger = LogManager.CreateLogger <ETLFileLogger>(config); logger.SubscribeToEvents(TestLogger.Write.Guid, EventLevel.Verbose); this.sessionName = ETLFileLogger.SessionPrefix + sName; while (TraceEventSession.GetActiveSession(this.sessionName) == null) { // Ensure session starts... Thread.Sleep(100); } // Even after the session is listed it seemingly isn't "ready", periodic test failures seem to occur without // an enforced pause here. This is awful and the author feels very bad about it. Sorry? Thread.Sleep(100); WriteTestEvents(); LogManager.DestroyLogger(logger); LogManager.Shutdown(); Assert.IsTrue(File.Exists(fullFilename)); return(fullFilename); }
private static void WorkerTraceEvents(object sender, DoWorkEventArgs e) { try { if (TraceEventSession.IsElevated() != true) { throw new InvalidOperationException( "Collecting ETW trace events requires administrative privileges."); } if (TraceEventSession.GetActiveSessionNames().Contains(SessionName)) { Debug.WriteLine( $"The session name '{SessionName}' is already in use, stopping existing and restart a new one."); TraceEventSession.GetActiveSession(SessionName).Stop(true); } // An End-To-End ETW Tracing Example: EventSource and TraceEvent // https://blogs.msdn.microsoft.com/vancem/2012/12/20/an-end-to-end-etw-tracing-example-eventsource-and-traceevent/ using (var traceEventSession = new TraceEventSession(SessionName)) { traceEventSession.StopOnDispose = true; using (var traceEventSource = new ETWTraceEventSource(SessionName, TraceEventSourceType.Session)) { traceEventSession.EnableProvider(OmaDmClient); traceEventSession.EnableProvider(OmaDmClientProvider); new RegisteredTraceEventParser(traceEventSource).All += (data => (sender as BackgroundWorker)?.ReportProgress(0, data.Clone())); traceEventSource.Process(); } } } catch (Exception ex) { Debug.WriteLine($"Exception: {ex}"); } }
public void 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")); }
protected override void OnStop() { // Guardrail for timeout RequestAdditionalTime(5000); // Check if any collector tasks are registered if (SilkUtility.CollectorTaskList.Any()) { // We pop terminated threads out of the list foreach (CollectorInstance CollectorTask in SilkUtility.CollectorTaskList) { try { CollectorTask.EventSource.StopProcessing(); TraceEventSession.GetActiveSession(CollectorTask.EventParseSessionName).Dispose(); SilkUtility.CollectorTaskList.Remove(CollectorTask); SilkUtility.WriteCollectorGuidMessageToServiceTextLog(CollectorTask.CollectorGUID, "Collector terminated", false); } catch { } } } // Write status to log SilkUtility.WriteToServiceTextLog("[+] SilkService stopped at: " + DateTime.Now); }
public void ChangingETLFilenameCausesManifestToBeEmittedInNewFile() { const string prefix = "rotateFile"; var files = new[] { prefix + "1.etl", prefix + "2.etl", prefix + "3.etl" }; var resultFiles = new List <string>(); LogManager.Start(); LogManager.SetConfiguration(null); LogManager.AllowEtwLogging = AllowEtwLoggingValues.Enabled; string sessionName = null; ETLFileLogger logger = null; foreach (var logFilename in files) { string fullFilename = Path.Combine(LogManager.DefaultDirectory, logFilename); try { File.Delete(fullFilename); } catch (DirectoryNotFoundException) { } if (sessionName == null) { sessionName = Path.GetFileNameWithoutExtension(logFilename); } if (logger == null) { logger = LogManager.CreateETWLogger(sessionName, ".") as ETLFileLogger; logger.SubscribeToEvents(TestLogger.Write.Guid, EventLevel.Verbose); while (TraceEventSession.GetActiveSession(ETLFileLogger.SessionPrefix + sessionName) == null) { // Ensure session starts... Thread.Sleep(100); } // Even after the session is listed it seemingly isn't "ready", periodic test failures seem to occur without // an enforced pause here. Thread.Sleep(100); } else { logger.Filename = fullFilename; } WriteTestEvents(); Assert.IsTrue(File.Exists(fullFilename)); resultFiles.Add(fullFilename); } LogManager.DestroyLogger(logger); LogManager.Shutdown(); foreach (var fullFilename in resultFiles) { // It is critical to ensure we create a new reader for each file so that any history across files is // not preserved using (var reader = new ETWFileProcessor(fullFilename)) { reader.EventProcessed += ValidateEventArgs; reader.Process(); Assert.AreEqual(4, reader.Count); } } }
public void CollectGcMetrics() { var logger = new TestLogger(LogLevel.Trace); string traceEventSessionName; using (var gcMetricsProvider = new GcMetricsProvider(logger)) { traceEventSessionName = gcMetricsProvider.TraceEventSessionName; gcMetricsProvider.IsMetricAlreadyCaptured.Should().BeFalse(); #if !NETCOREAPP2_1 //EventSource Microsoft-Windows-DotNETRuntime is only 2.2+, no gc metrics on 2.1 //repeat the allocation multiple times and make sure at least 1 GetSamples() call returns value // ReSharper disable once TooWideLocalVariableScope // ReSharper disable once RedundantAssignment var containsValue = false; for (var j = 0; j < 1000; j++) { for (var i = 0; i < 300_000; i++) { var _ = new int[100]; } GC.Collect(); for (var i = 0; i < 300_000; i++) { var _ = new int[100]; } GC.Collect(); var samples = gcMetricsProvider.GetSamples(); containsValue = samples != null && samples.Any(); if (containsValue) { break; } } if (PlatformDetection.IsDotNetFullFramework) { if (logger.Lines.Any(n => n.Contains("TraceEventSession initialization failed - GC metrics won't be collected"))) { // If initialization fails, (e.g. because ETW session initalization fails) we don't assert _output.WriteLine("Initialization failed. don't make assertions"); return; } } if (PlatformDetection.IsDotNetCore || PlatformDetection.IsDotNet5) { if (!logger.Lines.Any(n => n.Contains("OnEventWritten with GC"))) { // If no OnWritten with a GC event was called then initialization failed -> we don't assert _output.WriteLine("Initialization failed. don't make assertions"); return; } } containsValue.Should().BeTrue(); gcMetricsProvider.IsMetricAlreadyCaptured.Should().BeTrue(); #endif } if (PlatformDetection.IsDotNetFullFramework) { var traceEventSession = TraceEventSession.GetActiveSession(traceEventSessionName); traceEventSession.Should().BeNull(); } }
public void CollectGcMetrics() { var logger = new TestLogger(LogLevel.Trace); string traceEventSessionName; using (var gcMetricsProvider = new GcMetricsProvider(logger)) { traceEventSessionName = gcMetricsProvider.TraceEventSessionName; gcMetricsProvider.IsMetricAlreadyCaptured.Should().BeFalse(); #if !NETCOREAPP2_1 //EventSource Microsoft-Windows-DotNETRuntime is only 2.2+, no gc metrics on 2.1 //repeat the allocation multiple times and make sure at least 1 GetSamples() call returns value // ReSharper disable once TooWideLocalVariableScope // ReSharper disable once RedundantAssignment var containsValue = false; var hasGenSize = false; var hasGcTime = false; for (var j = 0; j < 10; j++) { for (var i = 0; i < 500; i++) { var array = new int[10000000]; // In order to make sure the line above is not optimized away, let's use the array: Console.WriteLine($"GC test, int[] allocated with length: {array.Length}"); } GC.Collect(2, GCCollectionMode.Forced, true, true); GC.WaitForFullGCComplete(); GC.Collect(2, GCCollectionMode.Forced, true, true); for (var i = 0; i < 500; i++) { var array = new int[10000000]; // In order to make sure the line above is not optimized away, let's use the array: Console.WriteLine($"GC test, int[] allocated with length: {array.Length}"); } GC.Collect(2, GCCollectionMode.Forced, true, true); GC.WaitForFullGCComplete(); GC.Collect(2, GCCollectionMode.Forced, true, true); var samples = gcMetricsProvider.GetSamples()?.ToArray(); containsValue = samples != null && samples.Any(); hasGenSize = samples != null && samples .Any(n => (n.KeyValue.Key.Contains("gen0size") || n.KeyValue.Key.Contains("gen1size") || n.KeyValue.Key.Contains("gen2size") || n.KeyValue.Key.Contains("gen3size")) && n.KeyValue.Value > 0); hasGcTime = samples != null && samples .Any(n => n.KeyValue.Key.Contains("clr.gc.time") && n.KeyValue.Value > 0); if (containsValue && hasGenSize && hasGcTime) { break; } } if (PlatformDetection.IsDotNetFullFramework) { if (logger.Lines.Any(n => n.Contains("TraceEventSession initialization failed - GC metrics won't be collected"))) { // If initialization fails, (e.g. because ETW session initalization fails) we don't assert _output.WriteLine("Initialization failed. don't make assertions"); return; } } if (PlatformDetection.IsDotNetCore || PlatformDetection.IsDotNet5) { if (!logger.Lines.Any(n => n.Contains("OnEventWritten with GC"))) { // If no OnWritten with a GC event was called then initialization failed -> we don't assert _output.WriteLine("Initialization failed. don't make assertions"); return; } } containsValue.Should().BeTrue(); hasGenSize.Should().BeTrue(); hasGcTime.Should().BeTrue(); gcMetricsProvider.IsMetricAlreadyCaptured.Should().BeTrue(); #endif } if (PlatformDetection.IsDotNetFullFramework) { var traceEventSession = TraceEventSession.GetActiveSession(traceEventSessionName); traceEventSession.Should().BeNull(); } }