Pulling in Noah's fix in event_pipe_lock_fix branch

Author: sywhang

src/vm/eventpipe.cpp

@@ -389,8 +389,9 @@ void EventPipe::DisableInternal(EventPipeSessionID id, EventPipeProviderCallback
         // Delete the flush timer.
         DeleteFlushTimerCallback();
 
-        // Flush all write buffers to make sure that all threads see the change.
-        FlushProcessWriteBuffers();
+        // Force all in-progress writes to either finish or cancel
+        // This is required to ensure we can safely flush and delete the buffers
+        s_pBufferManager->SuspendWriteEvent();
 
         // Write to the file.
         if (s_pFile != nullptr)
@@ -401,7 +402,10 @@ void EventPipe::DisableInternal(EventPipeSessionID id, EventPipeProviderCallback
 
             if (CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EventPipeRundown) > 0)
             {
-                // Before closing the file, do rundown.
+                // Before closing the file, do rundown. We have to re-enable event writing for this.
+
+                s_pBufferManager->ResumeWriteEvent();
+
                 const EventPipeProviderConfiguration RundownProviders[] = {
                     {W("Microsoft-Windows-DotNETRuntime"), 0x80020138, static_cast<unsigned int>(EventPipeEventLevel::Verbose), NULL},       // Public provider.
                     {W("Microsoft-Windows-DotNETRuntimeRundown"), 0x80020138, static_cast<unsigned int>(EventPipeEventLevel::Verbose), NULL} // Rundown provider.
@@ -425,6 +429,9 @@ void EventPipe::DisableInternal(EventPipeSessionID id, EventPipeProviderCallback
                 // Delete the rundown session.
                 s_pConfig->DeleteSession(s_pSession);
                 s_pSession = NULL;
+
+                // Suspend again after rundown session
+                s_pBufferManager->SuspendWriteEvent();
             }
 
             delete s_pFile;
@@ -437,6 +444,10 @@ void EventPipe::DisableInternal(EventPipeSessionID id, EventPipeProviderCallback
         // Delete deferred providers.
         // Providers can't be deleted during tracing because they may be needed when serializing the file.
         s_pConfig->DeleteDeferredProviders();
+
+        // ALlow WriteEvent to begin accepting work again so that sometime in the future
+        // we can re-enable events and they will be recorded
+        s_pBufferManager->ResumeWriteEvent();
     }
 }
 
@@ -912,4 +923,17 @@ EventPipeEventInstance *EventPipe::GetNextEvent()
     EventPipeProvider::InvokeCallback(eventPipeProviderCallbackData);
 }
 
+#ifdef DEBUG
+/* static */ bool EventPipe::IsLockOwnedByCurrentThread()
+{
+    return GetLock()->OwnedByCurrentThread();
+}
+
+/* static */ bool EventPipe::IsBufferManagerLockOwnedByCurrentThread()
+{
+    return s_pBufferManager->IsLockOwnedByCurrentThread();
+}
+#endif
+
+
 #endif // FEATURE_PERFTRACING

src/vm/eventpipe.h

@@ -333,6 +333,12 @@ class EventPipe
     // Get next event.
     static EventPipeEventInstance *GetNextEvent();
 
+#ifdef DEBUG
+    static bool IsLockOwnedByCurrentThread();
+    static bool IsBufferManagerLockOwnedByCurrentThread();
+#endif
+
+
     template<class T>
     static void RunWithCallbackPostponed(T f)
     {

src/vm/eventpipebuffer.cpp

@@ -7,10 +7,11 @@
 #include "eventpipe.h"
 #include "eventpipeeventinstance.h"
 #include "eventpipebuffer.h"
+#include "eventpipebuffermanager.h"
 
 #ifdef FEATURE_PERFTRACING
 
-EventPipeBuffer::EventPipeBuffer(unsigned int bufferSize)
+EventPipeBuffer::EventPipeBuffer(unsigned int bufferSize DEBUG_ARG(EventPipeThread* pWriterThread))
 {
     CONTRACTL
     {
@@ -19,13 +20,18 @@ EventPipeBuffer::EventPipeBuffer(unsigned int bufferSize)
         MODE_ANY;
     }
     CONTRACTL_END;
-
+    m_state = EventPipeBufferState::WRITABLE;
+#ifdef DEBUG
+    m_pWriterThread = pWriterThread;
+#endif
     m_pBuffer = new BYTE[bufferSize];
     memset(m_pBuffer, 0, bufferSize);
     m_pLimit = m_pBuffer + bufferSize;
     m_pCurrent = GetNextAlignedAddress(m_pBuffer);
 
-    m_mostRecentTimeStamp.QuadPart = 0;
+
+    QueryPerformanceCounter(&m_creationTimeStamp);
+    _ASSERTE(m_creationTimeStamp.QuadPart > 0);
     m_pLastPoppedEvent = NULL;
     m_pPrevBuffer = NULL;
     m_pNextBuffer = NULL;
@@ -41,6 +47,9 @@ EventPipeBuffer::~EventPipeBuffer()
     }
     CONTRACTL_END;
 
+    // We should never be deleting a buffer that a writer thread might still try to write to 
+    _ASSERTE(m_state == EventPipeBufferState::READ_ONLY);
+
     if(m_pBuffer != NULL)
     {
         delete[] m_pBuffer;
@@ -58,6 +67,9 @@ bool EventPipeBuffer::WriteEvent(Thread *pThread, EventPipeSession &session, Eve
     }
     CONTRACTL_END;
 
+    // We should never try to write to a buffer that isn't expecting to be written to.
+    _ASSERTE(m_state == EventPipeBufferState::WRITABLE);
+
     // Calculate the size of the event.
     unsigned int eventSize = sizeof(EventPipeEventInstance) + payload.GetSize();
 
@@ -106,9 +118,6 @@ bool EventPipeBuffer::WriteEvent(Thread *pThread, EventPipeSession &session, Eve
             payload.CopyData(pDataDest);
         }
 
-        // Save the most recent event timestamp.
-        m_mostRecentTimeStamp = *pInstance->GetTimeStamp();
-
     }
     EX_CATCH
     {
@@ -126,11 +135,11 @@ bool EventPipeBuffer::WriteEvent(Thread *pThread, EventPipeSession &session, Eve
     return success;
 }
 
-LARGE_INTEGER EventPipeBuffer::GetMostRecentTimeStamp() const
+LARGE_INTEGER EventPipeBuffer::GetCreationTimeStamp() const
 {
     LIMITED_METHOD_CONTRACT;
 
-    return m_mostRecentTimeStamp;
+    return m_creationTimeStamp;
 }
 
 EventPipeEventInstance* EventPipeBuffer::GetNext(EventPipeEventInstance *pEvent, LARGE_INTEGER beforeTimeStamp)
@@ -143,6 +152,8 @@ EventPipeEventInstance* EventPipeBuffer::GetNext(EventPipeEventInstance *pEvent,
     }
     CONTRACTL_END;
 
+    _ASSERTE(m_state == EventPipeBufferState::READ_ONLY);
+
     EventPipeEventInstance *pNextInstance = NULL;
     // If input is NULL, return the first event if there is one.
     if(pEvent == NULL)
@@ -212,6 +223,8 @@ EventPipeEventInstance* EventPipeBuffer::PeekNext(LARGE_INTEGER beforeTimeStamp)
     }
     CONTRACTL_END;
 
+    _ASSERTE(m_state == READ_ONLY);
+
     // Get the next event using the last popped event as a marker.
     return GetNext(m_pLastPoppedEvent, beforeTimeStamp);
 }
@@ -226,6 +239,8 @@ EventPipeEventInstance* EventPipeBuffer::PopNext(LARGE_INTEGER beforeTimeStamp)
     }
     CONTRACTL_END;
 
+    _ASSERTE(m_state == READ_ONLY);
+
     // Get the next event using the last popped event as a marker.
     EventPipeEventInstance *pNext = PeekNext(beforeTimeStamp);
     if(pNext != NULL)
@@ -236,6 +251,19 @@ EventPipeEventInstance* EventPipeBuffer::PopNext(LARGE_INTEGER beforeTimeStamp)
     return pNext;
 }
 
+EventPipeBufferState EventPipeBuffer::GetVolatileState()
+{
+    LIMITED_METHOD_CONTRACT;
+    return m_state.Load();
+}
+
+void EventPipeBuffer::ConvertToReadOnly()
+{
+    LIMITED_METHOD_CONTRACT;
+    _ASSERTE(m_pWriterThread->GetLock()->OwnedByCurrentThread());
+    m_state.Store(EventPipeBufferState::READ_ONLY);
+}
+
 #ifdef _DEBUG
 bool EventPipeBuffer::EnsureConsistency()
 {

src/vm/eventpipebuffer.h

@@ -12,6 +12,34 @@
 #include "eventpipeeventinstance.h"
 #include "eventpipesession.h"
 
+class EventPipeThread;
+
+
+// Synchronization
+//
+// EventPipeBuffer starts off writable and accumulates events in a buffer, then at some point converts to be readable and a second thread can
+// read back the events which have accumulated. The transition occurs when calling ConvertToReadOnly(). Write methods will assert if the buffer
+// isn't writable and read-related methods will assert if it isn't readable. Methods that have no asserts should have immutable results that
+// can be used at any point during the buffer's lifetime. The buffer has no internal locks so it is the caller's responsibility to synchronize
+// their usage.
+// Writing into the buffer and calling ConvertToReadOnly() is always done with EventPipeThread::m_lock held. The eventual reader thread can do
+// a few different things to ensure it sees a consistent state:
+// 1) Take the writer's EventPipeThread::m_lock at least once after the last time the writer writes events
+// 2) Use a memory barrier that prevents reader loads from being re-ordered earlier, such as the one that will occur implicitly by evaluating
+//    EventPipeBuffer::GetVolatileState()
+
+
+enum EventPipeBufferState
+{
+    // This buffer is currently assigned to a thread and pWriterThread may write events into it
+    // at any time
+    WRITABLE = 0,
+
+    // This buffer has been returned to the EventPipeBufferManager and pWriterThread is guaranteed
+    // to never access it again.
+    READ_ONLY = 1
+};
+
 class EventPipeBuffer
 {
 
@@ -24,6 +52,15 @@ class EventPipeBuffer
     // It is OK for the data payloads to be unaligned because they are opaque blobs that are copied via memcpy.
     const size_t AlignmentSize = 8;
 
+    // State transition WRITABLE -> READ_ONLY only occurs while holding the m_pWriterThread->m_lock;
+    // It can be read at any time
+    Volatile<EventPipeBufferState> m_state;
+
+    // Thread that is/was allowed to write into this buffer when m_state == WRITABLE
+#ifdef DEBUG
+    EventPipeThread* m_pWriterThread;
+#endif
+    
     // A pointer to the actual buffer.
     BYTE *m_pBuffer;
 
@@ -33,8 +70,10 @@ class EventPipeBuffer
     // The max write pointer (end of the buffer).
     BYTE *m_pLimit;
 
-    // The timestamp of the most recent event in the buffer.
-    LARGE_INTEGER m_mostRecentTimeStamp;
+    // The timestamp the buffer was created. If our clock source
+    // is monotonic then all events in the buffer should have
+    // timestamp >= this one. If not then all bets are off.
+    LARGE_INTEGER m_creationTimeStamp;
 
     // Used by PopNext as input to GetNext.
     // If NULL, no events have been popped.
@@ -89,7 +128,7 @@ class EventPipeBuffer
 
 public:
 
-    EventPipeBuffer(unsigned int bufferSize);
+    EventPipeBuffer(unsigned int bufferSize DEBUG_ARG(EventPipeThread* pWriterThread));
     ~EventPipeBuffer();
 
     // Write an event to the buffer.
@@ -100,8 +139,8 @@ class EventPipeBuffer
     //  - false: The write failed.  In this case, the buffer should be considered full.
     bool WriteEvent(Thread *pThread, EventPipeSession &session, EventPipeEvent &event, EventPipeEventPayload &payload, LPCGUID pActivityId, LPCGUID pRelatedActivityId, StackContents *pStack = NULL);
 
-    // Get the timestamp of the most recent event in the buffer.
-    LARGE_INTEGER GetMostRecentTimeStamp() const;
+    // Get the timestamp the buffer was created.
+    LARGE_INTEGER GetCreationTimeStamp() const;
 
     // Get the next event from the buffer as long as it is before the specified timestamp.
     // Input of NULL gets the first event.
@@ -113,6 +152,12 @@ class EventPipeBuffer
     // Get the next event from the buffer and mark it as read.
     EventPipeEventInstance* PopNext(LARGE_INTEGER beforeTimeStamp);
 
+    // Check the state of the buffer
+    EventPipeBufferState GetVolatileState();
+
+    // Convert the buffer writable to readable
+    void ConvertToReadOnly();
+
 #ifdef _DEBUG
     bool EnsureConsistency();
 #endif // _DEBUG