diff --git a/src/inc/clrconfigvalues.h b/src/inc/clrconfigvalues.h index 70e93707388e..46fad0f6d719 100644 --- a/src/inc/clrconfigvalues.h +++ b/src/inc/clrconfigvalues.h @@ -742,9 +742,10 @@ RETAIL_CONFIG_DWORD_INFO(EXTERNAL_AllowDComReflection, W("AllowDComReflection"), // EventPipe // RETAIL_CONFIG_DWORD_INFO(INTERNAL_EnableEventPipe, W("EnableEventPipe"), 0, "Enable/disable event pipe. Non-zero values enable tracing.") -RETAIL_CONFIG_STRING_INFO(INTERNAL_EventPipeOutputFile, W("EventPipeOutputFile"), "The full path including file name for the trace file that will be written when COMPlus_EnableEventPipe&=1") +RETAIL_CONFIG_STRING_INFO(INTERNAL_EventPipeOutputPath, W("EventPipeOutputPath"), "The full path excluding file name for the trace file that will be written when COMPlus_EnableEventPipe=1") RETAIL_CONFIG_STRING_INFO(INTERNAL_EventPipeConfig, W("EventPipeConfig"), "Configuration for EventPipe.") RETAIL_CONFIG_DWORD_INFO(INTERNAL_EventPipeRundown, W("EventPipeRundown"), 1, "Enable/disable eventpipe rundown.") +RETAIL_CONFIG_DWORD_INFO(INTERNAL_EventPipeCircularMB, W("EventPipeCircularMB"), 1024, "The EventPipe circular buffer size in megabytes.") #ifdef FEATURE_GDBJIT /// diff --git a/src/mscorlib/System.Private.CoreLib.csproj b/src/mscorlib/System.Private.CoreLib.csproj index fc76ffa81f61..b40bb53cb53b 100644 --- a/src/mscorlib/System.Private.CoreLib.csproj +++ b/src/mscorlib/System.Private.CoreLib.csproj @@ -526,6 +526,7 @@ + @@ -552,6 +553,9 @@ + + + @@ -592,7 +596,6 @@ - diff --git a/src/mscorlib/src/System/Diagnostics/Eventing/EventPipe.cs b/src/mscorlib/src/System/Diagnostics/Eventing/EventPipe.cs index 94ace3cca59d..d83dff8958db 100644 --- a/src/mscorlib/src/System/Diagnostics/Eventing/EventPipe.cs +++ b/src/mscorlib/src/System/Diagnostics/Eventing/EventPipe.cs @@ -127,6 +127,19 @@ internal void EnableProvider(string providerName, ulong keywords, uint loggingLe loggingLevel)); } + private void EnableProviderConfiguration(EventPipeProviderConfiguration providerConfig) + { + m_providers.Add(providerConfig); + } + + internal void EnableProviderRange(EventPipeProviderConfiguration[] providerConfigs) + { + foreach(EventPipeProviderConfiguration config in providerConfigs) + { + EnableProviderConfiguration(config); + } + } + internal void SetProfilerSamplingRate(TimeSpan minTimeBetweenSamples) { if(minTimeBetweenSamples.Ticks <= 0) diff --git a/src/mscorlib/src/System/Diagnostics/Eventing/EventPipeController.cs b/src/mscorlib/src/System/Diagnostics/Eventing/EventPipeController.cs new file mode 100644 index 000000000000..c0c2a4e5d35d --- /dev/null +++ b/src/mscorlib/src/System/Diagnostics/Eventing/EventPipeController.cs @@ -0,0 +1,408 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. +#if FEATURE_PERFTRACING +using Internal.IO; +using Microsoft.Win32; +using System.IO; +using System.Globalization; +using System.Reflection; +using System.Runtime.Versioning; +using System.Text; +using System.Threading; +using System.Threading.Tasks; + +namespace System.Diagnostics.Tracing +{ + /// + /// Simple out-of-process listener for controlling EventPipe. + /// The following environment variables are used to configure EventPipe: + /// - COMPlus_EnableEventPipe=1 : Enable EventPipe immediately for the life of the process. + /// - COMPlus_EnableEventPipe=4 : Enables this controller and creates a thread to listen for enable/disable events. + /// - COMPlus_EventPipeConfig : Provides the configuration in xperf string form for which providers/keywords/levels to be enabled. + /// If not specified, the default configuration is used. + /// - COMPlus_EventPipeOutputFile : The full path to the netperf file to be written. + /// - COMPlus_EventPipeCircularMB : The size in megabytes of the circular buffer. + /// Once the configuration is set and this controller is enabled, tracing is enabled by creating a marker file that this controller listens for. + /// Tracing is disabled by deleting the marker file. The marker file is the target trace file path with ".ctl" appended to it. For example, + /// if the trace file is /path/to/trace.netperf then the marker file is /path/to/trace.netperf.ctl. + /// This listener does not poll very often, and thus takes time to enable and disable tracing. This is by design to ensure that the listener does + /// not starve other threads on the system. + /// NOTE: If COMPlus_EnableEventPipe != 4 then this listener is not created and does not add any overhead to the process. + /// + internal sealed class EventPipeController + { + // Miscellaneous constants. + private const string DefaultAppName = "app"; + private const string NetPerfFileExtension = ".netperf"; + private const string ConfigFileSuffix = ".eventpipeconfig"; + private const int EnabledPollingIntervalMilliseconds = 1000; // 1 second + private const int DisabledPollingIntervalMilliseconds = 5000; // 5 seconds + private const uint DefaultCircularBufferMB = 1024; // 1 GB + private static readonly char[] ProviderConfigDelimiter = new char[] { ',' }; + private static readonly char[] ConfigComponentDelimiter = new char[] { ':' }; + private static readonly string[] ConfigFileLineDelimiters = new string[] { "\r\n", "\n" }; + private const char ConfigEntryDelimiter = '='; + + // Config file keys. + private const string ConfigKey_Providers = "Providers"; + private const string ConfigKey_CircularMB = "CircularMB"; + private const string ConfigKey_OutputPath = "OutputPath"; + private const string ConfigKey_ProcessID = "ProcessID"; + + // The default set of providers/keywords/levels. Used if an alternative configuration is not specified. + private static readonly EventPipeProviderConfiguration[] DefaultProviderConfiguration = new EventPipeProviderConfiguration[] + { + new EventPipeProviderConfiguration("Microsoft-Windows-DotNETRuntime", 0x4c14fccbd, 5), + new EventPipeProviderConfiguration("Microsoft-Windows-DotNETRuntimePrivate", 0x4002000b, 5), + new EventPipeProviderConfiguration("Microsoft-DotNETCore-SampleProfiler", 0x0, 5) + }; + + // Singleton controller instance. + private static EventPipeController s_controllerInstance = null; + + // Controller object state. + private Timer m_timer; + private string m_configFilePath; + private DateTime m_configFileUpdateTime; + private string m_traceFilePath = null; + private bool m_configFileExists = false; + + internal static void Initialize() + { + // Don't allow failures to propagate upstream. Ensure program correctness without tracing. + try + { + if (s_controllerInstance == null) + { + if (Config_EnableEventPipe > 0) + { + // Enable tracing immediately. + // It will be disabled automatically on shutdown. + EventPipe.Enable(BuildConfigFromEnvironment()); + } + else + { + // Create a new controller to listen for commands. + s_controllerInstance = new EventPipeController(); + } + } + } + catch { } + } + + private EventPipeController() + { + // Set the config file path. + m_configFilePath = Path.Combine(AppDomain.CurrentDomain.BaseDirectory, BuildConfigFileName()); + + // Initialize the timer, but don't set it to run. + // The timer will be set to run each time PollForTracingCommand is called. + m_timer = new Timer( + callback: new TimerCallback(PollForTracingCommand), + state: null, + dueTime: Timeout.Infinite, + period: Timeout.Infinite); + + // Trigger the first poll operation on the start-up path. + PollForTracingCommand(null); + } + + private void PollForTracingCommand(object state) + { + // Make sure that any transient errors don't cause the listener thread to exit. + try + { + // Check for existence of the config file. + // If the existence of the file has changed since the last time we checked or the update time has changed + // this means that we need to act on that change. + bool fileExists = File.Exists(m_configFilePath); + if (m_configFileExists != fileExists) + { + // Save the result. + m_configFileExists = fileExists; + + // Take the appropriate action. + if (fileExists) + { + // Enable tracing. + // Check for null here because it's possible that the configuration contains a process filter + // that doesn't match the current process. IF this occurs, we should't enable tracing. + EventPipeConfiguration config = BuildConfigFromFile(m_configFilePath); + if (config != null) + { + EventPipe.Enable(config); + } + } + else + { + // Disable tracing. + EventPipe.Disable(); + } + } + + // Schedule the timer to run again. + m_timer.Change(fileExists ? EnabledPollingIntervalMilliseconds : DisabledPollingIntervalMilliseconds, Timeout.Infinite); + } + catch { } + } + + private static EventPipeConfiguration BuildConfigFromFile(string configFilePath) + { + // Read the config file in once call. + byte[] configContents = File.ReadAllBytes(configFilePath); + + // Convert the contents to a string. + string strConfigContents = Encoding.UTF8.GetString(configContents); + + // Read all of the config options. + string outputPath = null; + string strProviderConfig = null; + string strCircularMB = null; + string strProcessID = null; + + // Split the configuration entries by line. + string[] configEntries = strConfigContents.Split(ConfigFileLineDelimiters, StringSplitOptions.RemoveEmptyEntries); + foreach (string configEntry in configEntries) + { + //`Split the key and value by '='. + string[] entryComponents = configEntry.Split(ConfigEntryDelimiter); + if(entryComponents.Length == 2) + { + string key = entryComponents[0]; + if (key.Equals(ConfigKey_Providers)) + { + strProviderConfig = entryComponents[1]; + } + else if (key.Equals(ConfigKey_OutputPath)) + { + outputPath = entryComponents[1]; + } + else if (key.Equals(ConfigKey_CircularMB)) + { + strCircularMB = entryComponents[1]; + } + else if (key.Equals(ConfigKey_ProcessID)) + { + strProcessID = entryComponents[1]; + } + } + } + + // Check the process ID filter if it is set. + if (!string.IsNullOrEmpty(strProcessID)) + { + // If set, bail out early if the specified process does not match the current process. + int processID = Convert.ToInt32(strProcessID); + if (processID != Win32Native.GetCurrentProcessId()) + { + return null; + } + } + + // Ensure that the output path is set. + if (string.IsNullOrEmpty(outputPath)) + { + throw new ArgumentNullException(nameof(outputPath)); + } + + // Build the full path to the trace file. + string traceFileName = BuildTraceFileName(); + string outputFile = Path.Combine(outputPath, traceFileName); + + // Get the circular buffer size. + uint circularMB = DefaultCircularBufferMB; + if(!string.IsNullOrEmpty(strCircularMB)) + { + circularMB = Convert.ToUInt32(strCircularMB); + } + + // Initialize a new configuration object. + EventPipeConfiguration config = new EventPipeConfiguration(outputFile, circularMB); + + // Set the provider configuration if specified. + if (!string.IsNullOrEmpty(strProviderConfig)) + { + SetProviderConfiguration(strProviderConfig, config); + } + else + { + // If the provider configuration isn't specified, use the default. + config.EnableProviderRange(DefaultProviderConfiguration); + } + + return config; + } + + private static EventPipeConfiguration BuildConfigFromEnvironment() + { + // Build the full path to the trace file. + string traceFileName = BuildTraceFileName(); + string outputFilePath = Path.Combine(Config_EventPipeOutputPath, traceFileName); + + // Create a new configuration object. + EventPipeConfiguration config = new EventPipeConfiguration( + outputFilePath, + Config_EventPipeCircularMB); + + // Get the configuration. + string strConfig = Config_EventPipeConfig; + if (!string.IsNullOrEmpty(strConfig)) + { + // If the configuration is specified, parse it and save it to the config object. + SetProviderConfiguration(strConfig, config); + } + else + { + // Specify the default configuration. + config.EnableProviderRange(DefaultProviderConfiguration); + } + + return config; + } + + private static string BuildConfigFileName() + { + return GetAppName() + ConfigFileSuffix; + } + + private static string BuildTraceFileName() + { + return GetAppName() + "." + Win32Native.GetCurrentProcessId() + NetPerfFileExtension; + } + + private static string GetAppName() + { + string appName = null; + Assembly entryAssembly = Assembly.GetEntryAssembly(); + if (entryAssembly != null) + { + AssemblyName assemblyName = entryAssembly.GetName(); + if (assemblyName != null) + { + appName = assemblyName.Name; + } + } + + if (string.IsNullOrEmpty(appName)) + { + appName = DefaultAppName; + } + + return appName; + } + + private static void SetProviderConfiguration(string strConfig, EventPipeConfiguration config) + { + if (string.IsNullOrEmpty(strConfig)) + { + throw new ArgumentNullException(nameof(strConfig)); + } + + // String must be of the form "providerName:keywords:level,providerName:keywords:level..." + string[] providers = strConfig.Split(ProviderConfigDelimiter); + foreach (string provider in providers) + { + string[] components = provider.Split(ConfigComponentDelimiter); + if (components.Length == 3) + { + string providerName = components[0]; + + // We use a try/catch block here because ulong.TryParse won't accept 0x at the beginning + // of a hex string. Thus, we either need to conditionally strip it or handle the exception. + // Given that this is not a perf-critical path, catching the exception is the simpler code. + ulong keywords = 0; + try + { + keywords = Convert.ToUInt64(components[1], 16); + } + catch { } + + uint level; + if (!uint.TryParse(components[2], out level)) + { + level = 0; + } + + config.EnableProvider(providerName, keywords, level); + } + } + } + + #region Configuration + + // Cache for COMPlus configuration variables. + private static int s_Config_EnableEventPipe = -1; + private static string s_Config_EventPipeConfig = null; + private static uint s_Config_EventPipeCircularMB = 0; + private static string s_Config_EventPipeOutputPath = null; + + private static int Config_EnableEventPipe + { + get + { + if (s_Config_EnableEventPipe == -1) + { + string strEnabledValue = CompatibilitySwitch.GetValueInternal("EnableEventPipe"); + if ((strEnabledValue == null) || (!int.TryParse(strEnabledValue, out s_Config_EnableEventPipe))) + { + s_Config_EnableEventPipe = 0; + } + } + + return s_Config_EnableEventPipe; + } + } + + private static string Config_EventPipeConfig + { + get + { + if (s_Config_EventPipeConfig == null) + { + s_Config_EventPipeConfig = CompatibilitySwitch.GetValueInternal("EventPipeConfig"); + } + + return s_Config_EventPipeConfig; + } + } + + private static uint Config_EventPipeCircularMB + { + get + { + if (s_Config_EventPipeCircularMB == 0) + { + string strCircularMB = CompatibilitySwitch.GetValueInternal("EventPipeCircularMB"); + if ((strCircularMB == null) || (!uint.TryParse(strCircularMB, out s_Config_EventPipeCircularMB))) + { + s_Config_EventPipeCircularMB = DefaultCircularBufferMB; + } + } + + return s_Config_EventPipeCircularMB; + } + } + + private static string Config_EventPipeOutputPath + { + get + { + if (s_Config_EventPipeOutputPath == null) + { + s_Config_EventPipeOutputPath = CompatibilitySwitch.GetValueInternal("EventPipeOutputPath"); + if (s_Config_EventPipeOutputPath == null) + { + s_Config_EventPipeOutputPath = "."; + } + } + + return s_Config_EventPipeOutputPath; + } + } + + #endregion Configuration + } +} + +#endif // FEATURE_PERFTRACING diff --git a/src/vm/assembly.cpp b/src/vm/assembly.cpp index 402b2b8c633f..d2551b5683a5 100644 --- a/src/vm/assembly.cpp +++ b/src/vm/assembly.cpp @@ -52,6 +52,10 @@ #include "peimagelayout.inl" +#ifdef FEATURE_PERFTRACING +#include "eventpipe.h" +#endif + // Define these macro's to do strict validation for jit lock and class init entry leaks. // This defines determine if the asserts that verify for these leaks are defined or not. @@ -1810,6 +1814,12 @@ INT32 Assembly::ExecuteMainMethod(PTRARRAYREF *stringArgs, BOOL waitForOtherThre // to get the TargetFrameworkMoniker for the app AppDomain * pDomain = pThread->GetDomain(); pDomain->SetRootAssembly(pMeth->GetAssembly()); + +#ifdef FEATURE_PERFTRACING + // Initialize the managed components of EventPipe and allow tracing to be started before Main. + EventPipe::InitializeManaged(); +#endif + hr = RunMain(pMeth, 1, &iRetVal, stringArgs); } } diff --git a/src/vm/ceemain.cpp b/src/vm/ceemain.cpp index b1de447cbcca..84dc7ab347ae 100644 --- a/src/vm/ceemain.cpp +++ b/src/vm/ceemain.cpp @@ -1024,11 +1024,6 @@ void EEStartupHelper(COINITIEE fFlags) SystemDomain::System()->PublishAppDomainAndInformDebugger(SystemDomain::System()->DefaultDomain()); #endif -#ifdef FEATURE_PERFTRACING - // Start the event pipe if requested. - EventPipe::EnableOnStartup(); -#endif // FEATURE_PERFTRACING - #endif // CROSSGEN_COMPILE SystemDomain::System()->Init(); diff --git a/src/vm/eventpipe.cpp b/src/vm/eventpipe.cpp index 42eea423a7a7..fc8b885ddf27 100644 --- a/src/vm/eventpipe.cpp +++ b/src/vm/eventpipe.cpp @@ -203,35 +203,19 @@ void EventPipe::Initialize() InitProvidersAndEvents(); } -void EventPipe::EnableOnStartup() +void EventPipe::InitializeManaged() { CONTRACTL { THROWS; GC_TRIGGERS; - MODE_ANY; + MODE_COOPERATIVE; + INJECT_FAULT(COMPlusThrowOM();); } CONTRACTL_END; - // Test COMPLUS variable to enable tracing at start-up. - if((CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EnableEventPipe) & 1) == 1) - { - SString outputPath; - outputPath.Printf("Process-%d.netperf", GetCurrentProcessId()); - - // Create a new session. - EventPipeSession *pSession = new EventPipeSession( - EventPipeSessionType::File, - 1024 /* 1 GB circular buffer */, - NULL, /* pProviders */ - 0 /* numProviders */); - - // Get the configuration from the environment. - GetConfigurationFromEnvironment(outputPath, pSession); - - // Enable the session. - Enable(outputPath, pSession); - } + MethodDescCallSite eventPipeInitialize(METHOD__EVENTPIPE_CONTROLLER__INITIALIZE); + eventPipeInitialize.Call(NULL); } void EventPipe::Shutdown() @@ -861,130 +845,6 @@ CrstStatic* EventPipe::GetLock() return &s_configCrst; } -void EventPipe::GetConfigurationFromEnvironment(SString &outputPath, EventPipeSession *pSession) -{ - LIMITED_METHOD_CONTRACT; - - // Set the output path if specified. - CLRConfigStringHolder wszOutputPath(CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EventPipeOutputFile)); - if(wszOutputPath != NULL) - { - outputPath.Set(wszOutputPath); - } - - // Read the the provider configuration from the environment if specified. - CLRConfigStringHolder wszConfig(CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EventPipeConfig)); - if(wszConfig == NULL) - { - pSession->EnableAllEvents(); - return; - } - - size_t len = wcslen(wszConfig); - if(len <= 0) - { - pSession->EnableAllEvents(); - return; - } - - // Parses a string with the following format: - // - // ProviderName:Keywords:Level[,]* - // - // For example: - // - // Microsoft-Windows-DotNETRuntime:0xCAFEBABE:2,Microsoft-Windows-DotNETRuntimePrivate:0xDEADBEEF:1 - // - // Each provider configuration is separated by a ',' and each component within the configuration is - // separated by a ':'. - - const WCHAR ProviderSeparatorChar = ','; - const WCHAR ComponentSeparatorChar = ':'; - size_t index = 0; - WCHAR *pProviderName = NULL; - UINT64 keywords = 0; - EventPipeEventLevel level = EventPipeEventLevel::Critical; - - while(index < len) - { - WCHAR * pCurrentChunk = &wszConfig[index]; - size_t currentChunkStartIndex = index; - size_t currentChunkEndIndex = 0; - - // Find the next chunk. - while(index < len && wszConfig[index] != ProviderSeparatorChar) - { - index++; - } - currentChunkEndIndex = index++; - - // Split the chunk into components. - size_t chunkIndex = currentChunkStartIndex; - - // Get the provider name. - size_t provNameStartIndex = chunkIndex; - size_t provNameEndIndex = currentChunkEndIndex; - - while(chunkIndex < currentChunkEndIndex && wszConfig[chunkIndex] != ComponentSeparatorChar) - { - chunkIndex++; - } - provNameEndIndex = chunkIndex++; - - size_t provNameLen = provNameEndIndex - provNameStartIndex; - pProviderName = new WCHAR[provNameLen+1]; - memcpy(pProviderName, &wszConfig[provNameStartIndex], provNameLen*sizeof(WCHAR)); - pProviderName[provNameLen] = '\0'; - - // Get the keywords. - size_t keywordsStartIndex = chunkIndex; - size_t keywordsEndIndex = currentChunkEndIndex; - - while(chunkIndex < currentChunkEndIndex && wszConfig[chunkIndex] != ComponentSeparatorChar) - { - chunkIndex++; - } - keywordsEndIndex = chunkIndex++; - - size_t keywordsLen = keywordsEndIndex - keywordsStartIndex; - WCHAR *wszKeywords = new WCHAR[keywordsLen+1]; - memcpy(wszKeywords, &wszConfig[keywordsStartIndex], keywordsLen*sizeof(WCHAR)); - wszKeywords[keywordsLen] = '\0'; - keywords = _wcstoui64(wszKeywords, NULL, 16); - delete[] wszKeywords; - wszKeywords = NULL; - - // Get the level. - size_t levelStartIndex = chunkIndex; - size_t levelEndIndex = currentChunkEndIndex; - - while(chunkIndex < currentChunkEndIndex && wszConfig[chunkIndex] != ComponentSeparatorChar) - { - chunkIndex++; - } - levelEndIndex = chunkIndex++; - - size_t levelLen = levelEndIndex - levelStartIndex; - WCHAR *wszLevel = new WCHAR[levelLen+1]; - memcpy(wszLevel, &wszConfig[levelStartIndex], levelLen*sizeof(WCHAR)); - wszLevel[levelLen] = '\0'; - level = (EventPipeEventLevel) wcstoul(wszLevel, NULL, 16); - delete[] wszLevel; - wszLevel = NULL; - - // Add a new EventPipeSessionProvider. - EventPipeSessionProvider *pSessionProvider = new EventPipeSessionProvider(pProviderName, keywords, level); - pSession->AddSessionProvider(pSessionProvider); - - // Free the provider name string. - if(pProviderName != NULL) - { - delete[] pProviderName; - pProviderName = NULL; - } - } -} - void EventPipe::SaveCommandLine(LPCWSTR pwzAssemblyPath, int argc, LPCWSTR *argv) { CONTRACTL diff --git a/src/vm/eventpipe.h b/src/vm/eventpipe.h index d5273c4974be..293347f3630b 100644 --- a/src/vm/eventpipe.h +++ b/src/vm/eventpipe.h @@ -231,12 +231,12 @@ class EventPipe // Initialize the event pipe. static void Initialize(); + // Initialize the managed code components of the event pipe. + static void InitializeManaged(); + // Shutdown the event pipe. static void Shutdown(); - // Enable tracing from the start-up path based on COMPLUS variable. - static void EnableOnStartup(); - // Enable tracing via the event pipe. static EventPipeSessionID Enable( LPCWSTR strOutputPath, @@ -295,10 +295,6 @@ class EventPipe // Enable the specified EventPipe session. static EventPipeSessionID Enable(LPCWSTR strOutputPath, EventPipeSession *pSession); - // Get the EnableOnStartup configuration from environment. - static void GetConfigurationFromEnvironment(SString &outputPath, EventPipeSession *pSession); - - // Callback function for the stack walker. For each frame walked, this callback is invoked. static StackWalkAction StackWalkCallback(CrawlFrame *pCf, StackContents *pData); diff --git a/src/vm/eventpipesession.cpp b/src/vm/eventpipesession.cpp index b10caf2f5b4e..2dd1a3f38df7 100644 --- a/src/vm/eventpipesession.cpp +++ b/src/vm/eventpipesession.cpp @@ -75,19 +75,6 @@ void EventPipeSession::AddSessionProvider(EventPipeSessionProvider *pProvider) m_pProviderList->AddSessionProvider(pProvider); } -void EventPipeSession::EnableAllEvents() -{ - CONTRACTL - { - THROWS; - GC_NOTRIGGER; - MODE_ANY; - } - CONTRACTL_END; - - m_pProviderList->EnableAllEvents(); -} - EventPipeSessionProvider* EventPipeSession::GetSessionProvider(EventPipeProvider *pProvider) { CONTRACTL @@ -118,12 +105,21 @@ EventPipeSessionProviderList::EventPipeSessionProviderList( for(unsigned int i=0; iGetProviderName(), - pConfig->GetKeywords(), - (EventPipeEventLevel)pConfig->GetLevel()); - m_pProviders->InsertTail(new SListElem(pProvider)); + // Enable all events if the provider name == '*', all keywords are on and the requested level == verbose. + if((wcscmp(W("*"), pConfig->GetProviderName()) == 0) && (pConfig->GetKeywords() == 0xFFFFFFFFFFFFFFFF) && ((EventPipeEventLevel)pConfig->GetLevel() == EventPipeEventLevel::Verbose) && (m_pCatchAllProvider == NULL)) + { + m_pCatchAllProvider = new EventPipeSessionProvider(NULL, 0xFFFFFFFFFFFFFFFF, EventPipeEventLevel::Verbose); + } + else + { + EventPipeSessionProvider *pProvider = new EventPipeSessionProvider( + pConfig->GetProviderName(), + pConfig->GetKeywords(), + (EventPipeEventLevel)pConfig->GetLevel()); + + m_pProviders->InsertTail(new SListElem(pProvider)); + } } } @@ -176,16 +172,6 @@ void EventPipeSessionProviderList::AddSessionProvider(EventPipeSessionProvider * } } -void EventPipeSessionProviderList::EnableAllEvents() -{ - LIMITED_METHOD_CONTRACT; - - if(m_pCatchAllProvider == NULL) - { - m_pCatchAllProvider = new EventPipeSessionProvider(NULL, 0xFFFFFFFFFFFFFFFF, EventPipeEventLevel::Verbose); - } -} - EventPipeSessionProvider* EventPipeSessionProviderList::GetSessionProvider( EventPipeProvider *pProvider) { diff --git a/src/vm/eventpipesession.h b/src/vm/eventpipesession.h index 5518e76097c6..2880677fb6f3 100644 --- a/src/vm/eventpipesession.h +++ b/src/vm/eventpipesession.h @@ -96,10 +96,6 @@ class EventPipeSession return m_sessionStartTimeStamp; } - // Enable all events. - // This is used for testing and is controlled via COMPLUS_EnableEventPipe. - void EnableAllEvents(); - // Add a new provider to the session. void AddSessionProvider(EventPipeSessionProvider *pProvider); @@ -115,8 +111,7 @@ class EventPipeSessionProviderList // The list of providers. SList> *m_pProviders; - // A catch-all provider used when tracing is enabled at start-up - // under (COMPlus_PerformanceTracing & 1) == 1. + // A catch-all provider used when tracing is enabled for all events. EventPipeSessionProvider *m_pCatchAllProvider; public: @@ -125,10 +120,6 @@ class EventPipeSessionProviderList EventPipeSessionProviderList(EventPipeProviderConfiguration *pConfigs, unsigned int numConfigs); ~EventPipeSessionProviderList(); - // Enable all events. - // This is used for testing and is controlled via COMPLUS_EnableEventPipe. - void EnableAllEvents(); - // Add a new session provider to the list. void AddSessionProvider(EventPipeSessionProvider *pProvider); diff --git a/src/vm/eventtrace.cpp b/src/vm/eventtrace.cpp index 3de630f12ab0..4ce7c0bd9c35 100644 --- a/src/vm/eventtrace.cpp +++ b/src/vm/eventtrace.cpp @@ -1642,81 +1642,6 @@ void BulkTypeEventLogger::FireBulkTypeEvent() } UINT16 nClrInstanceID = GetClrInstanceId(); -#if !defined(FEATURE_PAL) - // Normally, we'd use the MC-generated FireEtwBulkType for all this gunk, but - // it's insufficient as the bulk type event is too complex (arrays of structs of - // varying size). So we directly log the event via EventDataDescCreate and - // EventWrite - - // We use one descriptor for the count + one for the ClrInstanceID + 4 - // per batched type (to include fixed-size data + name + param count + param - // array). But the system limit of 128 descriptors per event kicks in way - // before the 64K event size limit, and we already limit our batch size - // (m_nBulkTypeValueCount) to stay within the 128 descriptor limit. - EVENT_DATA_DESCRIPTOR EventData[128]; - - UINT iDesc = 0; - - _ASSERTE(iDesc < _countof(EventData)); - EventDataDescCreate(&EventData[iDesc++], &m_nBulkTypeValueCount, sizeof(m_nBulkTypeValueCount)); - - _ASSERTE(iDesc < _countof(EventData)); - EventDataDescCreate(&EventData[iDesc++], &nClrInstanceID, sizeof(nClrInstanceID)); - - for (int iTypeData = 0; iTypeData < m_nBulkTypeValueCount; iTypeData++) - { - // Do fixed-size data as one bulk copy - _ASSERTE(iDesc < _countof(EventData)); - EventDataDescCreate( - &EventData[iDesc++], - &(m_rgBulkTypeValues[iTypeData].fixedSizedData), - sizeof(m_rgBulkTypeValues[iTypeData].fixedSizedData)); - - // Do var-sized data individually per field - - // Type name (nonexistent and thus empty on FEATURE_REDHAWK) - _ASSERTE(iDesc < _countof(EventData)); -#ifdef FEATURE_REDHAWK - EventDataDescCreate(&EventData[iDesc++], W(""), sizeof(WCHAR)); -#else // FEATURE_REDHAWK - LPCWSTR wszName = m_rgBulkTypeValues[iTypeData].sName.GetUnicode(); - EventDataDescCreate( - &EventData[iDesc++], - (wszName == NULL) ? W("") : wszName, - (wszName == NULL) ? sizeof(WCHAR) : (m_rgBulkTypeValues[iTypeData].sName.GetCount() + 1) * sizeof(WCHAR)); -#endif // FEATURE_REDHAWK - - // Type parameter count -#ifndef FEATURE_REDHAWK - m_rgBulkTypeValues[iTypeData].cTypeParameters = m_rgBulkTypeValues[iTypeData].rgTypeParameters.GetCount(); -#endif // FEATURE_REDHAWK - _ASSERTE(iDesc < _countof(EventData)); - EventDataDescCreate( - &EventData[iDesc++], - &(m_rgBulkTypeValues[iTypeData].cTypeParameters), - sizeof(m_rgBulkTypeValues[iTypeData].cTypeParameters)); - - // Type parameter array - if (m_rgBulkTypeValues[iTypeData].cTypeParameters > 0) - { - _ASSERTE(iDesc < _countof(EventData)); - EventDataDescCreate( - &EventData[iDesc++], -#ifdef FEATURE_REDHAWK - ((m_rgBulkTypeValues[iTypeData].cTypeParameters == 1) ? - &(m_rgBulkTypeValues[iTypeData].ullSingleTypeParameter) : - (ULONGLONG *) (m_rgBulkTypeValues[iTypeData].rgTypeParameters)), -#else - m_rgBulkTypeValues[iTypeData].rgTypeParameters.GetElements(), -#endif - sizeof(ULONGLONG) * m_rgBulkTypeValues[iTypeData].cTypeParameters); - } - } - - Win32EventWrite(Microsoft_Windows_DotNETRuntimeHandle, &BulkType, iDesc, EventData); - -#else // FEATURE_PAL - if(m_pBulkTypeEventBuffer == NULL) { // The buffer could not be allocated when this object was created, so bail. @@ -1770,7 +1695,6 @@ void BulkTypeEventLogger::FireBulkTypeEvent() FireEtwBulkType(m_nBulkTypeValueCount, GetClrInstanceId(), iSize, m_pBulkTypeEventBuffer); -#endif // FEATURE_PAL // Reset state m_nBulkTypeValueCount = 0; m_nBulkTypeValueByteCount = 0; @@ -4249,6 +4173,13 @@ void InitializeEventTracing() // a suitable token, this implementation has a different callback for every EventPipe provider // that ultimately funnels them all into a common handler. +#if defined(FEATURE_PAL) +// CLR_GCHEAPCOLLECT_KEYWORD is defined by the generated ETW manifest on Windows. +// On non-Windows, we need to make sure that this is defined. Given that we can't change +// the value due to compatibility, we specify it here rather than generating defines based on the manifest. +#define CLR_GCHEAPCOLLECT_KEYWORD 0x800000 +#endif // defined(FEATURE_PAL) + // CallbackProviderIndex provides a quick identification of which provider triggered the // ETW callback. enum CallbackProviderIndex @@ -4266,7 +4197,8 @@ VOID EtwCallbackCommon( CallbackProviderIndex ProviderIndex, ULONG ControlCode, UCHAR Level, - ULONGLONG MatchAnyKeyword) + ULONGLONG MatchAnyKeyword, + PVOID pFilterData) { LIMITED_METHOD_CONTRACT; @@ -4282,6 +4214,26 @@ VOID EtwCallbackCommon( GCEventKeyword keywords = static_cast(MatchAnyKeyword); GCEventLevel level = static_cast(Level); GCHeapUtilities::RecordEventStateChange(bIsPublicTraceHandle, keywords, level); + + // Special check for the runtime provider's GCHeapCollectKeyword. Profilers + // flick this to force a full GC. + if (g_fEEStarted && !g_fEEShutDown && bIsPublicTraceHandle && + ((MatchAnyKeyword & CLR_GCHEAPCOLLECT_KEYWORD) != 0)) + { + // Profilers may (optionally) specify extra data in the filter parameter + // to log with the GCStart event. + LONGLONG l64ClientSequenceNumber = 0; +#if !defined(FEATURE_PAL) + PEVENT_FILTER_DESCRIPTOR FilterData = (PEVENT_FILTER_DESCRIPTOR)pFilterData; + if ((FilterData != NULL) && + (FilterData->Type == 1) && + (FilterData->Size == sizeof(l64ClientSequenceNumber))) + { + l64ClientSequenceNumber = *(LONGLONG *) (FilterData->Ptr); + } +#endif // !defined(FEATURE_PAL) + ETW::GCLog::ForceGC(l64ClientSequenceNumber); + } } // Individual callbacks for each EventPipe provider. @@ -4297,7 +4249,7 @@ VOID EventPipeEtwCallbackDotNETRuntimeStress( { LIMITED_METHOD_CONTRACT; - EtwCallbackCommon(DotNETRuntimeStress, ControlCode, Level, MatchAnyKeyword); + EtwCallbackCommon(DotNETRuntimeStress, ControlCode, Level, MatchAnyKeyword, FilterData); } VOID EventPipeEtwCallbackDotNETRuntime( @@ -4311,7 +4263,7 @@ VOID EventPipeEtwCallbackDotNETRuntime( { LIMITED_METHOD_CONTRACT; - EtwCallbackCommon(DotNETRuntime, ControlCode, Level, MatchAnyKeyword); + EtwCallbackCommon(DotNETRuntime, ControlCode, Level, MatchAnyKeyword, FilterData); } VOID EventPipeEtwCallbackDotNETRuntimeRundown( @@ -4325,7 +4277,7 @@ VOID EventPipeEtwCallbackDotNETRuntimeRundown( { LIMITED_METHOD_CONTRACT; - EtwCallbackCommon(DotNETRuntimeRundown, ControlCode, Level, MatchAnyKeyword); + EtwCallbackCommon(DotNETRuntimeRundown, ControlCode, Level, MatchAnyKeyword, FilterData); } VOID EventPipeEtwCallbackDotNETRuntimePrivate( @@ -4339,7 +4291,7 @@ VOID EventPipeEtwCallbackDotNETRuntimePrivate( { WRAPPER_NO_CONTRACT; - EtwCallbackCommon(DotNETRuntimePrivate, ControlCode, Level, MatchAnyKeyword); + EtwCallbackCommon(DotNETRuntimePrivate, ControlCode, Level, MatchAnyKeyword, FilterData); } @@ -4491,7 +4443,7 @@ extern "C" return; } - EtwCallbackCommon(providerIndex, ControlCode, Level, MatchAnyKeyword); + EtwCallbackCommon(providerIndex, ControlCode, Level, MatchAnyKeyword, FilterData); // TypeSystemLog needs a notification when certain keywords are modified, so // give it a hook here. @@ -4551,23 +4503,6 @@ extern "C" { ETW::EnumerationLog::EnumerateForCaptureState(); } - - // Special check for the runtime provider's GCHeapCollectKeyword. Profilers - // flick this to force a full GC. - if (g_fEEStarted && !g_fEEShutDown && bIsPublicTraceHandle && - ((MatchAnyKeyword & CLR_GCHEAPCOLLECT_KEYWORD) != 0)) - { - // Profilers may (optionally) specify extra data in the filter parameter - // to log with the GCStart event. - LONGLONG l64ClientSequenceNumber = 0; - if ((FilterData != NULL) && - (FilterData->Type == 1) && - (FilterData->Size == sizeof(l64ClientSequenceNumber))) - { - l64ClientSequenceNumber = *(LONGLONG *) (FilterData->Ptr); - } - ETW::GCLog::ForceGC(l64ClientSequenceNumber); - } } #ifdef FEATURE_COMINTEROP if (ETW_EVENT_ENABLED(MICROSOFT_WINDOWS_DOTNETRUNTIME_PRIVATE_PROVIDER_Context, CCWRefCountChange)) diff --git a/src/vm/eventtracepriv.h b/src/vm/eventtracepriv.h index ae4f1c5b3d00..8e06daf5fd21 100644 --- a/src/vm/eventtracepriv.h +++ b/src/vm/eventtracepriv.h @@ -254,10 +254,8 @@ class BulkTypeEventLogger { private: -#ifdef FEATURE_PAL // The maximum event size, and the size of the buffer that we allocate to hold the event contents. static const size_t kSizeOfEventBuffer = 65536; -#endif // Estimate of how many bytes we can squeeze in the event data for the value struct // array. (Intentionally overestimate the size of the non-array parts to keep it safe.) @@ -299,9 +297,7 @@ class BulkTypeEventLogger // List of types we've batched. BulkTypeValue m_rgBulkTypeValues[kMaxCountTypeValues]; -#ifdef FEATURE_PAL BYTE *m_pBulkTypeEventBuffer; -#endif #ifdef FEATURE_REDHAWK int LogSingleType(EEType * pEEType); @@ -313,9 +309,7 @@ class BulkTypeEventLogger BulkTypeEventLogger() : m_nBulkTypeValueCount(0), m_nBulkTypeValueByteCount(0) -#ifdef FEATURE_PAL , m_pBulkTypeEventBuffer(NULL) -#endif { CONTRACTL { @@ -325,12 +319,9 @@ class BulkTypeEventLogger } CONTRACTL_END; -#ifdef FEATURE_PAL m_pBulkTypeEventBuffer = new (nothrow) BYTE[kSizeOfEventBuffer]; -#endif } -#ifdef FEATURE_PAL ~BulkTypeEventLogger() { CONTRACTL @@ -344,7 +335,6 @@ class BulkTypeEventLogger delete[] m_pBulkTypeEventBuffer; m_pBulkTypeEventBuffer = NULL; } -#endif void LogTypeAndParameters(ULONGLONG thAsAddr, ETW::TypeSystemLog::TypeLogBehavior typeLogBehavior); void FireBulkTypeEvent(); diff --git a/src/vm/mscorlib.h b/src/vm/mscorlib.h index 461c07df04f4..810cc72b633c 100644 --- a/src/vm/mscorlib.h +++ b/src/vm/mscorlib.h @@ -849,6 +849,11 @@ DEFINE_FIELD_U(rgiColumnNumber, StackFrameHelper, rgiColumnNumber) DEFINE_FIELD_U(rgiLastFrameFromForeignExceptionStackTrace, StackFrameHelper, rgiLastFrameFromForeignExceptionStackTrace) DEFINE_FIELD_U(iFrameCount, StackFrameHelper, iFrameCount) +#ifdef FEATURE_PERFTRACING +DEFINE_CLASS(EVENTPIPE_CONTROLLER, Tracing, EventPipeController) +DEFINE_METHOD(EVENTPIPE_CONTROLLER, INITIALIZE, Initialize, SM_RetVoid) +#endif + DEFINE_CLASS(STREAM, IO, Stream) DEFINE_METHOD(STREAM, BEGIN_READ, BeginRead, IM_ArrByte_Int_Int_AsyncCallback_Object_RetIAsyncResult) DEFINE_METHOD(STREAM, END_READ, EndRead, IM_IAsyncResult_RetInt) diff --git a/src/vm/namespace.h b/src/vm/namespace.h index 4395071559fe..47758e5a0e23 100644 --- a/src/vm/namespace.h +++ b/src/vm/namespace.h @@ -16,6 +16,7 @@ #define g_ResourcesNS g_SystemNS ".Resources" #define g_DiagnosticsNS g_SystemNS ".Diagnostics" #define g_CodeContractsNS g_DiagnosticsNS ".Contracts" +#define g_TracingNS g_DiagnosticsNS ".Tracing" #define g_AssembliesNS g_SystemNS ".Configuration.Assemblies" #define g_GlobalizationNS g_SystemNS ".Globalization" #define g_IsolatedStorageNS g_SystemNS ".IO.IsolatedStorage" diff --git a/tests/issues.targets b/tests/issues.targets index 987b3b577053..ef8dd508a57a 100644 --- a/tests/issues.targets +++ b/tests/issues.targets @@ -1774,5 +1774,11 @@ Bug + + + + Unable to write config file to app location + + diff --git a/tests/src/tracing/tracecontrol/TraceControl.cs b/tests/src/tracing/tracecontrol/TraceControl.cs new file mode 100644 index 000000000000..fbdc97abf893 --- /dev/null +++ b/tests/src/tracing/tracecontrol/TraceControl.cs @@ -0,0 +1,113 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using System; +using System.IO; +using System.Reflection; +using System.Threading; +using System.Threading.Tasks; +using Tracing.Tests.Common; + +using Microsoft.Diagnostics.Tracing; +using Microsoft.Diagnostics.Tracing.Parsers.Clr; + +namespace Tracing.Tests +{ + public static class TraceControlTest + { + private static string ConfigFileContents = @" +OutputPath=. +CircularMB=2048 +Providers=*:0xFFFFFFFFFFFFFFFF:5 +"; + + private const int BytesInOneMB = 1024 * 1024; + + /// + /// This test collects a trace of itself and then performs some basic validation on the trace. + /// + public static int Main(string[] args) + { + // Calculate the path to the config file. + string configFileName = Assembly.GetEntryAssembly().GetName().Name + ".eventpipeconfig"; + string configFilePath = Path.Combine(AppDomain.CurrentDomain.BaseDirectory, configFileName); + Console.WriteLine("Calculated config file path: " + configFilePath); + + // Write the config file to disk. + File.WriteAllText(configFilePath, ConfigFileContents); + Console.WriteLine("Wrote contents of config file."); + + // Wait 5 seconds to ensure that tracing has started. + Console.WriteLine("Waiting 5 seconds for the config file to be picked up by the next poll operation."); + Thread.Sleep(TimeSpan.FromSeconds(5)); + + // Do some work that we can look for in the trace. + Console.WriteLine("Do some work that will be captured by the trace."); + GC.Collect(2, GCCollectionMode.Forced); + Console.WriteLine("Done with the work."); + + // Delete the config file to start tracing. + File.Delete(configFilePath); + Console.WriteLine("Deleted the config file."); + + // Build the full path to the trace file. + string[] traceFiles = Directory.GetFiles(".", "*.netperf", SearchOption.TopDirectoryOnly); + Assert.Equal("traceFiles.Length == 1", traceFiles.Length, 1); + string traceFilePath = traceFiles[0]; + + // Poll the file system and wait for the trace file to be written. + Console.WriteLine("Wait for the config file deletion to be picked up and for the trace file to be written."); + + // Wait for 1 second, which is the poll time when tracing is enabled. + Thread.Sleep(TimeSpan.FromSeconds(1)); + + // Poll for file size changes to the trace file itself. When the size of the trace file hasn't changed for 5 seconds, consider it fully written out. + Console.WriteLine("Waiting for the trace file to be written. Poll every second to watch for 5 seconds of no file size changes."); + long lastSizeInBytes = 0; + DateTime timeOfLastChangeUTC = DateTime.UtcNow; + do + { + FileInfo traceFileInfo = new FileInfo(traceFilePath); + long currentSizeInBytes = traceFileInfo.Length; + Console.WriteLine("Trace file size: " + ((double)currentSizeInBytes / BytesInOneMB)); + + if (currentSizeInBytes > lastSizeInBytes) + { + lastSizeInBytes = currentSizeInBytes; + timeOfLastChangeUTC = DateTime.UtcNow; + } + + Thread.Sleep(TimeSpan.FromSeconds(1)); + + } while (DateTime.UtcNow.Subtract(timeOfLastChangeUTC) < TimeSpan.FromSeconds(5)); + + int retVal = 0; + + // Use TraceEvent to consume the trace file and look for the work that we did. + Console.WriteLine("Using TraceEvent to parse the file to find the work that was done during trace capture."); + using (var trace = TraceEventDispatcher.GetDispatcherFromFileName(traceFilePath)) + { + string gcReasonInduced = GCReason.Induced.ToString(); + string providerName = "Microsoft-Windows-DotNETRuntime"; + string gcTriggeredEventName = "GC/Triggered"; + + trace.Clr.GCTriggered += delegate (GCTriggeredTraceData data) + { + if (gcReasonInduced.Equals(data.Reason.ToString())) + { + Console.WriteLine("Detected an induced GC"); + retVal = 100; + } + }; + + trace.Process(); + } + + // Clean-up the resulting trace file. + File.Delete(traceFilePath); + + return retVal; + } + } +} diff --git a/tests/src/tracing/tracecontrol/tracecontrol.csproj b/tests/src/tracing/tracecontrol/tracecontrol.csproj new file mode 100644 index 000000000000..dca25a2e344d --- /dev/null +++ b/tests/src/tracing/tracecontrol/tracecontrol.csproj @@ -0,0 +1,29 @@ + + + + + Debug + AnyCPU + 2.0 + {8E3244CB-407F-4142-BAAB-E7A55901A5FA} + Exe + {786C830F-07A1-408B-BD7F-6EE04809D6DB};{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC} + ..\..\ + BuildAndRun + $(DefineConstants);STATIC + 0 + + + + + + + False + + + + + + + +