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();
        }
Пример #2
0
        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();
        }
Пример #3
0
        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();
        }
Пример #4
0
        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();
        }
Пример #6
0
 private static void DisableETW(TraceEventSession traceEventSession)
 {
     traceEventSession.Flush();
     Thread.Sleep(1010);  // Calls are async.
     traceEventSession.Dispose();
 }
Пример #7
0
        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();
        }
Пример #8
0
 public void StopEventTrace()
 {
     _session.Flush();
     _isFinished.Wait(TimeSpan.FromSeconds(5));
 }
Пример #9
0
 public void Stop()
 {
     _kernelSession.Flush();
     _kernelSession.Stop();
     _customSession?.Stop();
 }
Пример #10
0
 public void Stop()
 {
     _session.Flush();
     _session.Stop();
 }
Пример #11
0
 public void Stop()
 {
     _kernelSession.Flush();
     _kernelSession.Stop();
 }
Пример #12
0
        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();
        }
Пример #13
0
        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();
        }
Пример #14
0
        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);
        }