diff options
Diffstat (limited to 'src/vm/eventpipe.cpp')
-rw-r--r-- | src/vm/eventpipe.cpp | 448 |
1 files changed, 406 insertions, 42 deletions
diff --git a/src/vm/eventpipe.cpp b/src/vm/eventpipe.cpp index 98d382ea17..e041615efc 100644 --- a/src/vm/eventpipe.cpp +++ b/src/vm/eventpipe.cpp @@ -4,21 +4,58 @@ #include "common.h" #include "eventpipe.h" +#include "eventpipebuffermanager.h" +#include "eventpipeconfiguration.h" +#include "eventpipeevent.h" +#include "eventpipefile.h" +#include "eventpipeprovider.h" #include "eventpipejsonfile.h" #include "sampleprofiler.h" -CrstStatic EventPipe::s_initCrst; +#ifdef FEATURE_PAL +#include "pal.h" +#endif // FEATURE_PAL + +#ifdef FEATURE_PERFTRACING + +CrstStatic EventPipe::s_configCrst; bool EventPipe::s_tracingInitialized = false; -bool EventPipe::s_tracingEnabled = false; +EventPipeConfiguration* EventPipe::s_pConfig = NULL; +EventPipeBufferManager* EventPipe::s_pBufferManager = NULL; +EventPipeFile* EventPipe::s_pFile = NULL; +#ifdef _DEBUG +EventPipeFile* EventPipe::s_pSyncFile = NULL; EventPipeJsonFile* EventPipe::s_pJsonFile = NULL; +#endif // _DEBUG + +#ifdef FEATURE_PAL +// This function is auto-generated from /src/scripts/genEventPipe.py +extern "C" void InitProvidersAndEvents(); +#endif + +#ifdef FEATURE_PAL +// This function is auto-generated from /src/scripts/genEventPipe.py +extern "C" void InitProvidersAndEvents(); +#endif void EventPipe::Initialize() { STANDARD_VM_CONTRACT; - s_tracingInitialized = s_initCrst.InitNoThrow( + s_tracingInitialized = s_configCrst.InitNoThrow( CrstEventPipe, - (CrstFlags)(CRST_TAKEN_DURING_SHUTDOWN)); + (CrstFlags)(CRST_REENTRANCY | CRST_TAKEN_DURING_SHUTDOWN)); + + s_pConfig = new EventPipeConfiguration(); + s_pConfig->Initialize(); + + s_pBufferManager = new EventPipeBufferManager(); + +#ifdef FEATURE_PAL + // This calls into auto-generated code to initialize the runtime providers + // and events so that the EventPipe configuration lock isn't taken at runtime + InitProvidersAndEvents(); +#endif } void EventPipe::EnableOnStartup() @@ -32,9 +69,15 @@ void EventPipe::EnableOnStartup() CONTRACTL_END; // Test COMPLUS variable to enable tracing at start-up. - if(CLRConfig::GetConfigValue(CLRConfig::INTERNAL_PerformanceTracing) != 0) + if((CLRConfig::GetConfigValue(CLRConfig::INTERNAL_PerformanceTracing) & 1) == 1) { - Enable(); + SString outputPath; + outputPath.Printf("Process-%d.netperf", GetCurrentProcessId()); + Enable( + outputPath.GetUnicode(), + 1024 /* 1 GB circular buffer */, + NULL /* pProviders */, + 0 /* numProviders */); } } @@ -49,9 +92,24 @@ void EventPipe::Shutdown() CONTRACTL_END; Disable(); + + if(s_pConfig != NULL) + { + delete(s_pConfig); + s_pConfig = NULL; + } + if(s_pBufferManager != NULL) + { + delete(s_pBufferManager); + s_pBufferManager = NULL; + } } -void EventPipe::Enable() +void EventPipe::Enable( + LPCWSTR strOutputPath, + uint circularBufferSizeInMB, + EventPipeProviderConfiguration *pProviders, + int numProviders) { CONTRACTL { @@ -61,22 +119,38 @@ void EventPipe::Enable() } CONTRACTL_END; - if(!s_tracingInitialized) + // If tracing is not initialized or is already enabled, bail here. + if(!s_tracingInitialized || s_pConfig->Enabled()) { return; } - // Take the lock and enable tracing. - CrstHolder _crst(&s_initCrst); - s_tracingEnabled = true; - if(CLRConfig::GetConfigValue(CLRConfig::INTERNAL_PerformanceTracing) == 2) + // Take the lock before enabling tracing. + CrstHolder _crst(GetLock()); + + // Create the event pipe file. + SString eventPipeFileOutputPath(strOutputPath); + s_pFile = new EventPipeFile(eventPipeFileOutputPath); + +#ifdef _DEBUG + if((CLRConfig::GetConfigValue(CLRConfig::INTERNAL_PerformanceTracing) & 2) == 2) { - // File placed in current working directory. + // Create a synchronous file. + SString eventPipeSyncFileOutputPath; + eventPipeSyncFileOutputPath.Printf("Process-%d.sync.netperf", GetCurrentProcessId()); + s_pSyncFile = new EventPipeFile(eventPipeSyncFileOutputPath); + + // Create a JSON file. SString outputFilePath; outputFilePath.Printf("Process-%d.PerfView.json", GetCurrentProcessId()); s_pJsonFile = new EventPipeJsonFile(outputFilePath); } +#endif // _DEBUG + // Enable tracing. + s_pConfig->Enable(circularBufferSizeInMB, pProviders, numProviders); + + // Enable the sample profiler SampleProfiler::Enable(); } @@ -90,76 +164,246 @@ void EventPipe::Disable() } CONTRACTL_END; - CrstHolder _crst(&s_initCrst); - s_tracingEnabled = false; - SampleProfiler::Disable(); + // Don't block GC during clean-up. + GCX_PREEMP(); + + // Take the lock before disabling tracing. + CrstHolder _crst(GetLock()); + + if(s_pConfig->Enabled()) + { + // Disable the profiler. + SampleProfiler::Disable(); + + // Disable tracing. + s_pConfig->Disable(); + + // Flush all write buffers to make sure that all threads see the change. + FlushProcessWriteBuffers(); + + // Write to the file. + 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); + s_pFile = NULL; + } +#ifdef _DEBUG + if(s_pSyncFile != NULL) + { + delete(s_pSyncFile); + s_pSyncFile = NULL; + } + if(s_pJsonFile != NULL) + { + delete(s_pJsonFile); + s_pJsonFile = NULL; + } +#endif // _DEBUG + + // De-allocate buffers. + s_pBufferManager->DeAllocateBuffers(); + + // Delete deferred providers. + // Providers can't be deleted during tracing because they may be needed when serializing the file. + s_pConfig->DeleteDeferredProviders(); + } +} - if(s_pJsonFile != NULL) +bool EventPipe::Enabled() +{ + LIMITED_METHOD_CONTRACT; + + bool enabled = false; + if(s_pConfig != NULL) { - delete(s_pJsonFile); - s_pJsonFile = NULL; + enabled = s_pConfig->Enabled(); } + + return enabled; } -bool EventPipe::EventEnabled(GUID& providerID, INT64 keyword) +EventPipeProvider* EventPipe::CreateProvider(const GUID &providerID, EventPipeCallback pCallbackFunction, void *pCallbackData) { CONTRACTL { - NOTHROW; - GC_NOTRIGGER; + THROWS; + GC_TRIGGERS; MODE_ANY; } CONTRACTL_END; - // TODO: Implement filtering. - return false; + return new EventPipeProvider(providerID, pCallbackFunction, pCallbackData); } -void EventPipe::WriteEvent(GUID& providerID, INT64 eventID, BYTE *pData, size_t length, bool sampleStack) +void EventPipe::DeleteProvider(EventPipeProvider *pProvider) +{ + CONTRACTL + { + THROWS; + GC_TRIGGERS; + MODE_ANY; + } + CONTRACTL_END; + + // Take the lock to make sure that we don't have a race + // between disabling tracing and deleting a provider + // where we hold a provider after tracing has been disabled. + CrstHolder _crst(GetLock()); + + if(pProvider != NULL) + { + if(Enabled()) + { + // Save the provider until the end of the tracing session. + pProvider->SetDeleteDeferred(); + } + else + { + // Delete the provider now. + // NOTE: This will remove it from all of the EventPipe data structures. + delete(pProvider); + } + } +} + +void EventPipe::WriteEvent(EventPipeEvent &event, BYTE *pData, unsigned int length, LPCGUID pActivityId, LPCGUID pRelatedActivityId) { CONTRACTL { NOTHROW; GC_NOTRIGGER; MODE_ANY; + PRECONDITION(s_pBufferManager != NULL); } CONTRACTL_END; - StackContents stackContents; - bool stackWalkSucceeded; + // Exit early if the event is not enabled. + if(!event.IsEnabled()) + { + return; + } - if(sampleStack) + // Get the current thread; + Thread *pThread = GetThread(); + if(pThread == NULL) { - stackWalkSucceeded = WalkManagedStackForCurrentThread(stackContents); + // We can't write an event without the thread object. + return; } - // TODO: Write the event. + if(!s_pConfig->RundownEnabled() && s_pBufferManager != NULL) + { + if(!s_pBufferManager->WriteEvent(pThread, event, pData, length, pActivityId, pRelatedActivityId)) + { + // 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, + pActivityId, + pRelatedActivityId); + + if(s_pFile != NULL) + { + s_pFile->WriteEvent(instance); + } + } + +#ifdef _DEBUG + { + GCX_PREEMP(); + + // Create an instance of the event for the synchronous path. + EventPipeEventInstance instance( + event, + pThread->GetOSThreadId(), + pData, + length, + pActivityId, + pRelatedActivityId); + + // Write to the EventPipeFile if it exists. + if(s_pSyncFile != NULL) + { + s_pSyncFile->WriteEvent(instance); + } + + // Write to the EventPipeJsonFile if it exists. + if(s_pJsonFile != NULL) + { + s_pJsonFile->WriteEvent(instance); + } + } +#endif // _DEBUG } -void EventPipe::WriteSampleProfileEvent(Thread *pThread, StackContents &stackContents) +void EventPipe::WriteSampleProfileEvent(Thread *pSamplingThread, EventPipeEvent *pEvent, Thread *pTargetThread, StackContents &stackContents, BYTE *pData, unsigned int length) { CONTRACTL { NOTHROW; GC_TRIGGERS; MODE_PREEMPTIVE; - PRECONDITION(pThread != NULL); } CONTRACTL_END; - EX_TRY + // Write the event to the thread's buffer. + if(s_pBufferManager != NULL) { - if(s_pJsonFile != NULL) + // Specify the sampling thread as the "current thread", so that we select the right buffer. + // Specify the target thread so that the event gets properly attributed. + if(!s_pBufferManager->WriteEvent(pSamplingThread, *pEvent, pData, length, NULL /* pActivityId */, NULL /* pRelatedActivityId */, pTargetThread, &stackContents)) { - CommonEventFields eventFields; - QueryPerformanceCounter(&eventFields.TimeStamp); - eventFields.ThreadID = pThread->GetOSThreadId(); + // 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; + } + } + +#ifdef _DEBUG + { + GCX_PREEMP(); + + // Create an instance for the synchronous path. + SampleProfilerEventInstance instance(*pEvent, pTargetThread, pData, length); + stackContents.CopyTo(instance.GetStack()); - static SString message(W("THREAD_TIME")); - s_pJsonFile->WriteEvent(eventFields, message, stackContents); + // Write to the EventPipeFile. + if(s_pSyncFile != NULL) + { + s_pSyncFile->WriteEvent(instance); + } + + // Write to the EventPipeJsonFile if it exists. + if(s_pJsonFile != NULL) + { + s_pJsonFile->WriteEvent(instance); } } - EX_CATCH{} EX_END_CATCH(SwallowAllExceptions); +#endif // _DEBUG } bool EventPipe::WalkManagedStackForCurrentThread(StackContents &stackContents) @@ -173,8 +417,12 @@ bool EventPipe::WalkManagedStackForCurrentThread(StackContents &stackContents) CONTRACTL_END; Thread *pThread = GetThread(); - _ASSERTE(pThread != NULL); - return WalkManagedStackForThread(pThread, stackContents); + if(pThread != NULL) + { + return WalkManagedStackForThread(pThread, stackContents); + } + + return false; } bool EventPipe::WalkManagedStackForThread(Thread *pThread, StackContents &stackContents) @@ -232,3 +480,119 @@ StackWalkAction EventPipe::StackWalkCallback(CrawlFrame *pCf, StackContents *pDa // Continue the stack walk. return SWA_CONTINUE; } + +EventPipeConfiguration* EventPipe::GetConfiguration() +{ + LIMITED_METHOD_CONTRACT; + + return s_pConfig; +} + +CrstStatic* EventPipe::GetLock() +{ + LIMITED_METHOD_CONTRACT; + + return &s_configCrst; +} + +void QCALLTYPE EventPipeInternal::Enable( + __in_z LPCWSTR outputFile, + unsigned int circularBufferSizeInMB, + long profilerSamplingRateInNanoseconds, + EventPipeProviderConfiguration *pProviders, + int numProviders) +{ + QCALL_CONTRACT; + + BEGIN_QCALL; + SampleProfiler::SetSamplingRate(profilerSamplingRateInNanoseconds); + EventPipe::Enable(outputFile, circularBufferSizeInMB, pProviders, numProviders); + END_QCALL; +} + +void QCALLTYPE EventPipeInternal::Disable() +{ + QCALL_CONTRACT; + + BEGIN_QCALL; + EventPipe::Disable(); + END_QCALL; +} + +INT_PTR QCALLTYPE EventPipeInternal::CreateProvider( + GUID providerID, + EventPipeCallback pCallbackFunc) +{ + QCALL_CONTRACT; + + EventPipeProvider *pProvider = NULL; + + BEGIN_QCALL; + + pProvider = EventPipe::CreateProvider(providerID, pCallbackFunc, NULL); + + END_QCALL; + + return reinterpret_cast<INT_PTR>(pProvider); +} + +INT_PTR QCALLTYPE EventPipeInternal::DefineEvent( + INT_PTR provHandle, + unsigned int eventID, + __int64 keywords, + unsigned int eventVersion, + unsigned int level, + void *pMetadata, + unsigned int metadataLength) +{ + QCALL_CONTRACT; + + EventPipeEvent *pEvent = NULL; + + BEGIN_QCALL; + + _ASSERTE(provHandle != NULL); + _ASSERTE(pMetadata != NULL); + EventPipeProvider *pProvider = reinterpret_cast<EventPipeProvider *>(provHandle); + pEvent = pProvider->AddEvent(eventID, keywords, eventVersion, (EventPipeEventLevel)level, (BYTE *)pMetadata, metadataLength); + _ASSERTE(pEvent != NULL); + + END_QCALL; + + return reinterpret_cast<INT_PTR>(pEvent); +} + +void QCALLTYPE EventPipeInternal::DeleteProvider( + INT_PTR provHandle) +{ + QCALL_CONTRACT; + BEGIN_QCALL; + + if(provHandle != NULL) + { + EventPipeProvider *pProvider = reinterpret_cast<EventPipeProvider*>(provHandle); + EventPipe::DeleteProvider(pProvider); + } + + END_QCALL; +} + +void QCALLTYPE EventPipeInternal::WriteEvent( + INT_PTR eventHandle, + unsigned int eventID, + void *pData, + unsigned int length, + LPCGUID pActivityId, + LPCGUID pRelatedActivityId) +{ + QCALL_CONTRACT; + BEGIN_QCALL; + + _ASSERTE(eventHandle != NULL); + EventPipeEvent *pEvent = reinterpret_cast<EventPipeEvent *>(eventHandle); + EventPipe::WriteEvent(*pEvent, (BYTE *)pData, length, pActivityId, pRelatedActivityId); + + END_QCALL; +} + +#endif // FEATURE_PERFTRACING |