Enable Symbolic Rundown for EventPipe (#11582)

Author: brianrob

src/inc/eventtracebase.h

@@ -103,7 +103,18 @@ enum EtwThreadFlags
 
 
 #else //defined(FEATURE_PAL)
+#if defined(FEATURE_PERFTRACING)
+#define ETW_INLINE
+#define ETWOnStartup(StartEventName, EndEventName)
+#define ETWFireEvent(EventName)
 
+#define ETW_TRACING_INITIALIZED(RegHandle) (TRUE)
+#define ETW_EVENT_ENABLED(Context, EventDescriptor) (EventPipeHelper::Enabled() || XplatEventLogger::IsEventLoggingEnabled())
+#define ETW_CATEGORY_ENABLED(Context, Level, Keyword) (EventPipeHelper::Enabled() || XplatEventLogger::IsEventLoggingEnabled())
+#define ETW_TRACING_ENABLED(Context, EventDescriptor) (EventEnabled##EventDescriptor())
+#define ETW_TRACING_CATEGORY_ENABLED(Context, Level, Keyword) (EventPipeHelper::Enabled() || XplatEventLogger::IsEventLoggingEnabled())
+#define ETW_PROVIDER_ENABLED(ProviderSymbol) (TRUE)
+#else //defined(FEATURE_PERFTRACING)
 #define ETW_INLINE  
 #define ETWOnStartup(StartEventName, EndEventName)
 #define ETWFireEvent(EventName)
@@ -114,7 +125,7 @@ enum EtwThreadFlags
 #define ETW_TRACING_ENABLED(Context, EventDescriptor) (EventEnabled##EventDescriptor())
 #define ETW_TRACING_CATEGORY_ENABLED(Context, Level, Keyword) (XplatEventLogger::IsEventLoggingEnabled())
 #define ETW_PROVIDER_ENABLED(ProviderSymbol) (TRUE)
-
+#endif // defined(FEATURE_PERFTRACING)
 #endif // !defined(FEATURE_PAL)
 
 #else // FEATURE_EVENT_TRACE
@@ -217,6 +228,14 @@ extern BOOL g_fEEIJWStartup;
 
 #define GetClrInstanceId()  (static_cast<UINT16>(g_nClrInstanceId))
 
+#if defined(FEATURE_PERFTRACING)
+class EventPipeHelper
+{
+public:
+    static bool Enabled();
+};
+#endif // defined(FEATURE_PERFTRACING)
+
 #if defined(FEATURE_EVENT_TRACE) || defined(FEATURE_EVENTSOURCE_XPLAT)
 
 #include "clrconfig.h"

src/vm/eventpipe.cpp

@@ -185,6 +185,19 @@ void EventPipe::Disable()
         LARGE_INTEGER disableTimeStamp;
         QueryPerformanceCounter(&disableTimeStamp);
         s_pBufferManager->WriteAllBuffersToFile(s_pFile, disableTimeStamp);
+
+        // Before closing the file, do rundown.
+        s_pConfig->EnableRundown();
+
+        // Ask the runtime to emit rundown events.
+        if(g_fEEStarted && !g_fEEShutDown)
+        {
+            ETW::EnumerationLog::EndRundown();
+        }
+
+        // Disable the event pipe now that rundown is complete.
+        s_pConfig->Disable();
+
         if(s_pFile != NULL)
         {
             delete(s_pFile);
@@ -208,6 +221,19 @@ void EventPipe::Disable()
     }
 }
 
+bool EventPipe::Enabled()
+{
+    LIMITED_METHOD_CONTRACT;
+
+    bool enabled = false;
+    if(s_pConfig != NULL)
+    {
+        enabled = s_pConfig->Enabled();
+    }
+
+    return enabled;
+}
+
 void EventPipe::WriteEvent(EventPipeEvent &event, BYTE *pData, unsigned int length)
 {
     CONTRACTL
@@ -233,14 +259,29 @@ void EventPipe::WriteEvent(EventPipeEvent &event, BYTE *pData, unsigned int leng
         return;
     }
 
-    if(s_pBufferManager != NULL)
+    if(!s_pConfig->RundownEnabled() && s_pBufferManager != NULL)
     {
         if(!s_pBufferManager->WriteEvent(pThread, event, pData, length))
         {
             // This is used in DEBUG to make sure that we don't log an event synchronously that we didn't log to the buffer.
             return;
         }
     }
+    else if(s_pConfig->RundownEnabled())
+    {
+        // Write synchronously to the file.
+        // We're under lock and blocking the disabling thread.
+        EventPipeEventInstance instance(
+            event,
+            pThread->GetOSThreadId(),
+            pData,
+            length);
+
+        if(s_pFile != NULL)
+        {
+            s_pFile->WriteEvent(instance);
+        }
+    }
 
 #ifdef _DEBUG
     {

src/vm/eventpipe.h

@@ -7,10 +7,7 @@
 
 #ifdef FEATURE_PERFTRACING
 
-#include "crst.h"
-#include "eventpipeprovider.h"
-#include "stackwalk.h"
-
+class CrstStatic;
 class EventPipeConfiguration;
 class EventPipeEvent;
 class EventPipeFile;
@@ -19,6 +16,17 @@ class EventPipeBuffer;
 class EventPipeBufferManager;
 class MethodDesc;
 class SampleProfilerEventInstance;
+struct EventPipeProviderConfiguration;
+
+// Define the event pipe callback to match the ETW callback signature.
+typedef void (*EventPipeCallback)(
+    LPCGUID SourceID,
+    ULONG IsEnabled,
+    UCHAR Level,
+    ULONGLONG MatchAnyKeywords,
+    ULONGLONG MatchAllKeywords,
+    void *FilterData,
+    void *CallbackContext);
 
 class StackContents
 {
@@ -168,6 +176,9 @@ class EventPipe
         // Disable tracing via the event pipe.
         static void Disable();
 
+        // Specifies whether or not the event pipe is enabled.
+        static bool Enabled();
+
         // Write out an event.
         // Data is written as a serialized blob matching the ETW serialization conventions.
         static void WriteEvent(EventPipeEvent &event, BYTE *pData, unsigned int length);
@@ -215,6 +226,25 @@ struct EventPipeProviderConfiguration
 
 public:
 
+    EventPipeProviderConfiguration()
+    {
+        LIMITED_METHOD_CONTRACT;
+        m_pProviderName = NULL;
+        m_keywords = NULL;
+        m_loggingLevel = 0;
+    }
+
+    EventPipeProviderConfiguration(
+        LPCWSTR pProviderName,
+        UINT64 keywords,
+        unsigned int loggingLevel)
+    {
+        LIMITED_METHOD_CONTRACT;
+        m_pProviderName = pProviderName;
+        m_keywords = keywords;
+        m_loggingLevel = loggingLevel;
+    }
+
     LPCWSTR GetProviderName() const
     {
         LIMITED_METHOD_CONTRACT;

src/vm/eventpipebuffermanager.cpp

@@ -760,7 +760,12 @@ bool EventPipeBufferList::EnsureConsistency()
         nodeCount++;
 
         // Check for consistency of the buffer itself.
-        _ASSERTE(pIter->EnsureConsistency());
+        // NOTE: We can't check the last buffer because the owning thread could
+        // be writing to it, which could result in false asserts.
+        if(pIter->GetNext() != NULL)
+        {
+            _ASSERTE(pIter->EnsureConsistency());
+        }
 
         // Check for cycles.
         _ASSERTE(nodeCount <= m_bufferCount);

src/vm/eventpipeconfiguration.cpp

@@ -19,6 +19,7 @@ EventPipeConfiguration::EventPipeConfiguration()
     STANDARD_VM_CONTRACT;
 
     m_enabled = false;
+    m_rundownEnabled = false;
     m_circularBufferSizeInBytes = 1024 * 1024 * 1000; // Default to 1000MB.
     m_pEnabledProviderList = NULL;
     m_pProviderList = new SList<SListElem<EventPipeProvider*>>();
@@ -266,6 +267,7 @@ void EventPipeConfiguration::Disable()
     }
 
     m_enabled = false;
+    m_rundownEnabled = false;
 
     // Free the enabled providers list.
     if(m_pEnabledProviderList != NULL)
@@ -281,6 +283,38 @@ bool EventPipeConfiguration::Enabled() const
     return m_enabled;
 }
 
+bool EventPipeConfiguration::RundownEnabled() const
+{
+    LIMITED_METHOD_CONTRACT;
+    return m_rundownEnabled;
+}
+
+void EventPipeConfiguration::EnableRundown()
+{
+    CONTRACTL
+    {
+        THROWS;
+        GC_NOTRIGGER;
+        MODE_ANY;
+        // Lock must be held by EventPipe::Disable.
+        PRECONDITION(EventPipe::GetLock()->OwnedByCurrentThread());
+    }
+    CONTRACTL_END;
+
+    // Build the rundown configuration.
+    _ASSERTE(m_pEnabledProviderList == NULL);
+    const unsigned int numRundownProviders = 2;
+    EventPipeProviderConfiguration rundownProviders[numRundownProviders];
+    rundownProviders[0] = EventPipeProviderConfiguration(W("e13c0d23-ccbc-4e12-931b-d9cc2eee27e4"), 0x80020138, static_cast<unsigned int>(EventPipeEventLevel::Verbose)); // Public provider.
+    rundownProviders[1] = EventPipeProviderConfiguration(W("a669021c-c450-4609-a035-5af59af4df18"), 0x80020138, static_cast<unsigned int>(EventPipeEventLevel::Verbose)); // Rundown provider.
+
+    // Enable rundown.
+    m_rundownEnabled = true;
+
+    // Enable tracing.  The circular buffer size doesn't matter because we're going to write all events synchronously during rundown.
+    Enable(1 /* circularBufferSizeInMB */, rundownProviders, numRundownProviders);
+}
+
 EventPipeEventInstance* EventPipeConfiguration::BuildEventMetadataEvent(EventPipeEventInstance &sourceInstance, BYTE *pPayloadData, unsigned int payloadLength)
 {
     CONTRACTL
@@ -351,14 +385,16 @@ EventPipeEnabledProviderList::EventPipeEnabledProviderList(
     }
     CONTRACTL_END;
 
+    m_pProviders = NULL;
+    m_pCatchAllProvider = NULL;
+    m_numProviders = 0;
+
     // Test COMPLUS variable to enable tracing at start-up.
     // If tracing is enabled at start-up create the catch-all provider and always return it.
     if((CLRConfig::GetConfigValue(CLRConfig::INTERNAL_PerformanceTracing) & 1) == 1)
     {
         m_pCatchAllProvider = new EventPipeEnabledProvider();
         m_pCatchAllProvider->Set(NULL, 0xFFFFFFFF, EventPipeEventLevel::Verbose);
-        m_pProviders = NULL;
-        m_numProviders = 0;
         return;
     }
 

src/vm/eventpipeconfiguration.h

@@ -62,6 +62,12 @@ class EventPipeConfiguration
     // Get the status of the event pipe.
     bool Enabled() const;
 
+    // Determine if rundown is enabled.
+    bool RundownEnabled() const;
+
+    // Enable the well-defined symbolic rundown configuration.
+    void EnableRundown();
+
     // Get the event used to write metadata to the event stream.
     EventPipeEventInstance* BuildEventMetadataEvent(EventPipeEventInstance &sourceInstance, BYTE *pPayloadData = NULL, unsigned int payloadLength = 0);
 
@@ -92,6 +98,9 @@ class EventPipeConfiguration
     // The provider ID for the configuration event pipe provider.
     // This provider is used to emit configuration events.
     static const GUID s_configurationProviderID;
+
+    // True if rundown is enabled.
+    Volatile<bool> m_rundownEnabled;
 };
 
 class EventPipeEnabledProviderList

src/vm/eventpipeprovider.h

@@ -7,6 +7,7 @@
 
 #ifdef FEATURE_PERFTRACING
 
+#include "eventpipe.h"
 #include "eventpipeconfiguration.h"
 #include "slist.h"
 

src/vm/eventtrace.cpp

@@ -197,7 +197,10 @@ BOOL IsRundownNgenKeywordEnabledAndNotSuppressed()
 {
     LIMITED_METHOD_CONTRACT;
 
-    return 
+    return
+#ifdef FEATURE_PERFTRACING
+        EventPipeHelper::Enabled() ||
+#endif // FEATURE_PERFTRACING
     (
         ETW_TRACING_CATEGORY_ENABLED(
             MICROSOFT_WINDOWS_DOTNETRUNTIME_RUNDOWN_PROVIDER_Context, 
@@ -7385,3 +7388,12 @@ VOID ETW::EnumerationLog::EnumerationHelper(Module *moduleFilter, BaseDomain *do
 }
 
 #endif // !FEATURE_REDHAWK
+
+#ifdef FEATURE_PERFTRACING
+#include "eventpipe.h"
+bool EventPipeHelper::Enabled()
+{
+    LIMITED_METHOD_CONTRACT;
+    return EventPipe::Enabled();
+}
+#endif // FEATURE_PERFTRACING