Example #1
0
        public static int RunAndValidateEventCounts(
            Dictionary <string, ExpectedEventCount> expectedEventCounts,
            Action eventGeneratingAction,
            SessionConfiguration?sessionConfiguration = null,
            Func <EventPipeEventSource, Func <int> > optionalTraceValidator = null)
        {
            Logger.logger.Log("==TEST STARTING==");
            var test = new IpcTraceTest(expectedEventCounts, eventGeneratingAction, sessionConfiguration, optionalTraceValidator);

            try
            {
                var ret = test.Validate();
                if (ret == 100)
                {
                    Logger.logger.Log("==TEST FINISHED: PASSED!==");
                }
                else
                {
                    Logger.logger.Log("==TEST FINISHED: FAILED!==");
                }
                return(ret);
            }
            catch (Exception e)
            {
                Logger.logger.Log(e.ToString());
                Logger.logger.Log("==TEST FINISHED: FAILED!==");
                return(-1);
            }
        }
Example #2
0
        public static int RunAndValidateEventCounts(
            Dictionary <string, ExpectedEventCount> expectedEventCounts,
            Action eventGeneratingAction,
            List <EventPipeProvider> providers,
            int circularBufferMB = 1024,
            Func <EventPipeEventSource, Func <int> > optionalTraceValidator = null)
        {
            Logger.logger.Log("==TEST STARTING==");
            var test = new IpcTraceTest(expectedEventCounts, eventGeneratingAction, providers, circularBufferMB, optionalTraceValidator);

            try
            {
                var ret = test.Validate();
                if (ret == 100)
                {
                    Logger.logger.Log("==TEST FINISHED: PASSED!==");
                }
                else
                {
                    Logger.logger.Log("==TEST FINISHED: FAILED!==");
                }
                return(ret);
            }
            catch (Exception e)
            {
                Logger.logger.Log(e.ToString());
                Logger.logger.Log("==TEST FINISHED: FAILED!==");
                return(-1);
            }
        }
Example #3
0
        public static int RunAndValidateEventCounts(
            Dictionary <string, ExpectedEventCount> expectedEventCounts,
            Action eventGeneratingAction,
            SessionConfiguration?sessionConfiguration = null,
            Func <EventPipeEventSource, Func <int> > optionalTraceValidator = null)
        {
            Console.WriteLine("TEST STARTING");
            var test = new IpcTraceTest(expectedEventCounts, eventGeneratingAction, sessionConfiguration, optionalTraceValidator);

            try
            {
                var ret = test.Validate();
                if (ret == 100)
                {
                    Console.WriteLine("TEST PASSED!");
                }
                return(ret);
            }
            catch (Exception e)
            {
                Console.WriteLine("TEST FAILED!");
                Console.WriteLine(e);
                return(-1);
            }
        }
Example #4
0
        private int Validate()
        {
            // FIXME: This is a bandaid fix for a deadlock in EventPipeEventSource caused by
            // the lazy caching in the Regex library.  The caching creates a ConcurrentDictionary
            // and because it is the first one in the process, it creates an EventSource which
            // results in a deadlock over a lock in EventPipe.  These lines should be removed once the
            // underlying issue is fixed by forcing these events to try to be written _before_ we shutdown.
            //
            // see: https://github.com/dotnet/runtime/pull/1794 for details on the issue
            //
            var emptyConcurrentDictionary = new ConcurrentDictionary <string, string>();

            emptyConcurrentDictionary["foo"] = "bar";
            var __count = emptyConcurrentDictionary.Count;

            var isClean = IpcTraceTest.EnsureCleanEnvironment();

            if (!isClean)
            {
                return(-1);
            }
            // CollectTracing returns before EventPipe::Enable has returned, so the
            // the sources we want to listen for may not have been enabled yet.
            // We'll use this sentinel EventSource to check if Enable has finished
            ManualResetEvent sentinelEventReceived = new ManualResetEvent(false);
            var sentinelTask = new Task(() =>
            {
                Logger.logger.Log("Started sending sentinel events...");
                while (!sentinelEventReceived.WaitOne(50))
                {
                    SentinelEventSource.Log.SentinelEvent();
                }
                Logger.logger.Log("Stopped sending sentinel events");
            });

            sentinelTask.Start();

            int        processId          = Process.GetCurrentProcess().Id;;
            object     threadSync         = new object(); // for locking eventpipeSessionId access
            ulong      eventpipeSessionId = 0;
            Func <int> optionalTraceValidationCallback = null;
            var        readerTask = new Task(() =>
            {
                Logger.logger.Log("Connecting to EventPipe...");
                using (var eventPipeStream = new StreamProxy(EventPipeClient.CollectTracing(processId, _sessionConfiguration, out var sessionId)))
                {
                    if (sessionId == 0)
                    {
                        Logger.logger.Log("Failed to connect to EventPipe!");
                        throw new ApplicationException("Failed to connect to EventPipe");
                    }
                    Logger.logger.Log($"Connected to EventPipe with sessionID '0x{sessionId:x}'");

                    lock (threadSync)
                    {
                        eventpipeSessionId = sessionId;
                    }

                    Logger.logger.Log("Creating EventPipeEventSource...");
                    using (EventPipeEventSource source = new EventPipeEventSource(eventPipeStream))
                    {
                        Logger.logger.Log("EventPipeEventSource created");

                        source.Dynamic.All += (eventData) =>
                        {
                            try
                            {
                                if (eventData.ProviderName == "SentinelEventSource")
                                {
                                    if (!sentinelEventReceived.WaitOne(0))
                                    {
                                        Logger.logger.Log("Saw sentinel event");
                                    }
                                    sentinelEventReceived.Set();
                                }

                                else if (_actualEventCounts.TryGetValue(eventData.ProviderName, out _))
                                {
                                    _actualEventCounts[eventData.ProviderName]++;
                                }
                                else
                                {
                                    Logger.logger.Log($"Saw new provider '{eventData.ProviderName}'");
                                    _actualEventCounts[eventData.ProviderName] = 1;
                                }
                            }
                            catch (Exception e)
                            {
                                Logger.logger.Log("Exception in Dynamic.All callback " + e.ToString());
                            }
                        };
                        Logger.logger.Log("Dynamic.All callback registered");

                        if (_optionalTraceValidator != null)
                        {
                            Logger.logger.Log("Running optional trace validator");
                            optionalTraceValidationCallback = _optionalTraceValidator(source);
                            Logger.logger.Log("Finished running optional trace validator");
                        }

                        Logger.logger.Log("Starting stream processing...");
                        try
                        {
                            source.Process();
                        }
                        catch (Exception e)
                        {
                            Logger.logger.Log($"Exception thrown while reading; dumping culprit stream to disk...");
                            eventPipeStream.DumpStreamToDisk();
                            // rethrow it to fail the test
                            throw e;
                        }
                        Logger.logger.Log("Stopping stream processing");
                        Logger.logger.Log($"Dropped {source.EventsLost} events");
                    }
                }
            });

            readerTask.Start();
            sentinelEventReceived.WaitOne();

            Logger.logger.Log("Starting event generating action...");
            _eventGeneratingAction();
            Logger.logger.Log("Stopping event generating action");

            var stopTask = Task.Run(() =>
            {
                Logger.logger.Log("Sending StopTracing command...");
                lock (threadSync) // eventpipeSessionId
                {
                    EventPipeClient.StopTracing(processId, eventpipeSessionId);
                }
                Logger.logger.Log("Finished StopTracing command");
            });

            // Should throw if the reader task throws any exceptions
            Task.WaitAll(readerTask, stopTask);
            Logger.logger.Log("Reader task finished");

            foreach (var(provider, expectedCount) in _expectedEventCounts)
            {
                if (_actualEventCounts.TryGetValue(provider, out var actualCount))
                {
                    if (!expectedCount.Validate(actualCount))
                    {
                        return(Fail($"Event count mismatch for provider \"{provider}\": expected {expectedCount}, but saw {actualCount}"));
                    }
                }
                else
                {
                    return(Fail($"No events for provider \"{provider}\""));
                }
            }

            if (optionalTraceValidationCallback != null)
            {
                Logger.logger.Log("Validating optional callback...");
                // reader thread should be dead now, no need to lock
                return(optionalTraceValidationCallback());
            }
            else
            {
                return(100);
            }
        }