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(); }
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(); }
private static void PrintSummaryInfo() { session.Flush(); Console.ForegroundColor = ConsoleColor.DarkYellow; Console.WriteLine("\nMemory Allocations:"); // 100GB = 107,374,182,400 bytes, so min-width = 15 Console.WriteLine(" {0,15:N0} bytes currently allocated", GC.GetTotalMemory(forceFullCollection: false)); Console.WriteLine(" {0,15:N0} bytes have been allocated in total", totalBytesAllocated); var totalGC = gen0 + gen1 + gen2 + gen3; var testTime = stopTime - startTime; Console.WriteLine("GC Collections:\n {0,5:N0} in total ({1:N0} excluding B/G)", totalGC + gen2Background, totalGC); Console.WriteLine(" {0,5:N0} - generation 0 - {1}", gen0, Statistics(binning[0])); Console.WriteLine(" {0,5:N0} - generation 1 - {1}", gen1, Statistics(binning[1])); Console.WriteLine(" {0,5:N0} - generation 2 - {1}", gen2, Statistics(binning[2])); Console.WriteLine(" {0,5:N0} - generation 2 (B/G)", gen2Background); if (gen3 > 0) { Console.WriteLine(" {0,5:N0} - generation 3 (LOH)", gen3); } Console.WriteLine("Time in GC : {0,12:N2} ms ({1:N2} ms avg per/GC) ", timeInGc, timeInGc / totalGC); Console.WriteLine("Time in test: {0,12:N2} ms ({1:P2} spent in GC)", testTime, timeInGc / testTime); Console.WriteLine("Total GC Pause time : {0,12:N2} ms", totalGcPauseTime); Console.WriteLine("Largest GC Pause time: {0,12:N2} ms", largestGcPause); Console.ResetColor(); }
public void Test_EventSource_EtwManifestGeneration() { RemoteInvokeOptions options = new RemoteInvokeOptions { TimeOut = 300_000 /* ms */ }; RemoteExecutor.Invoke(() => { RemoteInvokeOptions localOptions = new RemoteInvokeOptions { TimeOut = 300_000 /* ms */ }; using (RemoteInvokeHandle handle = RemoteExecutor.Invoke(() => { var es = new SimpleEventSource(); for (var i = 0; i < 100; i++) { es.WriteSimpleInt(i); Thread.Sleep(100); } }, localOptions)) { var etlFileName = @"file.etl"; var tracesession = new TraceEventSession("testname", etlFileName); tracesession.EnableProvider("SimpleEventSource"); Thread.Sleep(TimeSpan.FromSeconds(5)); tracesession.Flush(); tracesession.DisableProvider("SimpleEventSource"); tracesession.Dispose(); var manifestExists = false; var max_retries = 50; for (int i = 0; i < max_retries; i++) { if (VerifyManifestAndRemoveFile(etlFileName)) { manifestExists = true; break; } Thread.Sleep(1000); } Assert.True(manifestExists); } }, options).Dispose(); }
public void TraceProcessForDuration(int duration, string traceName) { var tracesession = new TraceEventSession("testname", _traceName); foreach (var provider in _providers) { tracesession.EnableProvider(provider.Name, (TraceEventLevel)provider.EventLevel, (ulong)provider.Keywords); } tracesession.EnableProvider("My-Test-EventSource"); System.Threading.Thread.Sleep(duration * 1000); tracesession.Flush(); tracesession.DisableProvider("My-Test-EventSource"); tracesession.Dispose(); }
private static void DisableETW(TraceEventSession traceEventSession) { traceEventSession.Flush(); Thread.Sleep(1010); // Calls are async. traceEventSession.Dispose(); }
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.Dynamic.All += onEvent; traceEventSource.UnhandledEvent += onEvent; traceEventSource.Process(); // Expect at least one manifest event. Assert.True(hasManifestEvents); } logger.Dispose(); }
public void StopEventTrace() { _session.Flush(); _isFinished.Wait(TimeSpan.FromSeconds(5)); }
public void Stop() { _kernelSession.Flush(); _kernelSession.Stop(); _customSession?.Stop(); }
public void Stop() { _session.Flush(); _session.Stop(); }
public void Stop() { _kernelSession.Flush(); _kernelSession.Stop(); }
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(); }
static void Main(string[] args) { // TODO // - allow to specify PID of running process (DON'T kill it at the end!!) // - put some stats in a "margin" and display the output on the RH 80% of the screen // - GC pauses, for info see // - https://blogs.msdn.microsoft.com/maoni/2014/12/22/gc-etw-events-1/ // - https://blogs.msdn.microsoft.com/maoni/2014/12/25/gc-etw-events-3/ // - https://blogs.msdn.microsoft.com/maoni/2015/11/20/are-you-glad/ // - https://blogs.msdn.microsoft.com/maoni/2006/06/07/suspending-and-resuming-threads-for-gc/ ResetStats(); var sessionName = "GCVisualiser"; session = new TraceEventSession(sessionName); session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, (ulong)(ClrTraceEventParser.Keywords.GC)); // The ETW collection thread starts receiving all events immediately, but we filter on the Process Id var processingTask = Task.Factory.StartNew(StartProcessingEvents, TaskCreationOptions.LongRunning); var exename = args[0]; var procname = Path.GetFileNameWithoutExtension(exename); var existingProcs = Process.GetProcessesByName(procname); var process = Process.Start(exename); // check for some shell executing the process, eg comemu/cmder if (!process.ProcessName.Equals(procname, StringComparison.OrdinalIgnoreCase)) { var cmp = new ProcessComparer(); Process subprocess = null; while (!process.HasExited) { Thread.Sleep(100); Console.WriteLine($"Trying to find '{procname}' process..."); subprocess = Process.GetProcessesByName(procname).Except(existingProcs, cmp).FirstOrDefault(); if (subprocess != null) { break; } } // one last time if (subprocess == null) { Thread.Sleep(100); Console.WriteLine($"Last attempt to find '{procname}' process"); subprocess = Process.GetProcessesByName(procname).Except(existingProcs, cmp).FirstOrDefault(); } if (subprocess == null) { Console.WriteLine($"'{procname}' process not found, goodbye"); return; } else { process = subprocess; } } ProcessIdsUsedInRuns.Add(process.Id); Console.CancelKeyPress += (sender, e) => { Console.WriteLine("\nConsole being killed, tidying up\n"); session.Dispose(); if (process.HasExited == false) { process.Kill(); } Console.WriteLine(); }; PrintSymbolInformation(); Console.WriteLine("Visualising GC Events, press <ENTER>, <ESC> or 'q' to exit"); Console.WriteLine("You can also push 's' at any time and the current summary will be displayed"); Console.WriteLine("You can also push 'r' at any time to reset the counters"); ConsoleKeyInfo cki; while (process.HasExited == false) { if (Console.KeyAvailable == false) { Thread.Sleep(250); continue; } cki = Console.ReadKey(); if (cki.Key == ConsoleKey.Enter || cki.Key == ConsoleKey.Escape || cki.Key == ConsoleKey.Q) { break; } if (cki.Key == ConsoleKey.S) { lock (ConsoleLock) { PrintSummaryInfo(); } } else if (cki.Key == ConsoleKey.R) { ResetStats(); } } if (process.HasExited == false) { process.Kill(); } // Flush the session before we finish, so that we get all the events possible session.Flush(); // wait a little while for all events to come through (Flush() doesn't seem to do this?) Thread.Sleep(3000); // Now kill the session completely session.Dispose(); var completed = processingTask.Wait(millisecondsTimeout: 3000); if (!completed) { Console.WriteLine("\nWait timed out, the Processing Task is still running"); } PrintSummaryInfo(); Console.WriteLine(); }
public override TestResult[] Execute(ITestMethod testMethod) { TestResult[] errorResults = ValidateElevated(testMethod); if (errorResults != null) { return(errorResults); } Exception signatureException = GetMethodSignatureException(testMethod); if (signatureException != null) { return(testMethod.CreateExceptionResult(signatureException)); } var runParameters = TestRunParameters.Read(); string logFolder = runParameters.LogFolder; bool shouldLog = !string.IsNullOrEmpty(logFolder); if (shouldLog) { try { logFolder = CreateLogFolder(logFolder, testMethod.TestMethodName); } catch (Exception e) { return(testMethod.CreateExceptionResult(e)); } } int iterations = runParameters.Iterations; var results = new TestResult[iterations]; for (int iteration = 1; iteration <= iterations; iteration++) { string sessionName = $"{testMethod.TestMethodName}-{iteration}"; using (var session = new TraceEventSession(sessionName)) { EnableKernelProviders(session, shouldLog); TraceEventDispatcher source; ZippedETLWriter writer = null; if (shouldLog) { string etlPath = Path.Combine(logFolder, $"Iteration{iteration}.etl"); source = new ETWReloggerTraceEventSource(sessionName, TraceEventSourceType.Session, etlPath); writer = new ZippedETLWriter(etlPath); } else { source = session.Source; } EnableProviders(session); PerformanceTestContext context = CreateContext(source); Task <TestResult> testTask = Task.Run(() => testMethod.Invoke(new object[] { context })); // This is a blocking call that in the case of ETWReloggerTraceEventSource, must be run on the same // thread as ETWReloggerTraceEventSource was created on. It will become unblocked when the // PerformanceTestContext calls StopProcessing on the source. source.Process(); TestResult result = testTask.Result; string displayName = testMethod.TestMethodName; if (iterations > 1) { displayName += $" [{iteration}/{iterations}]"; } result.DisplayName = displayName; session.Flush(); OnIterationEnded(context); context.LogScenarios(); context.LogMemoryDelta(); context.LogMessage($"{displayName} completed. {session.EventsLost} events lost."); context.WriteLogsToResult(result, writer); results[iteration - 1] = result; } } return(results); }