src/vm/eventpipe.cpp

   1 // Licensed to the .NET Foundation under one or more agreements.
   2 // The .NET Foundation licenses this file to you under the MIT license.
   3 // See the LICENSE file in the project root for more information.
   4
   5 #include "common.h"
   6 #include "eventpipe.h"
   7 #include "eventpipebuffermanager.h"
   8 #include "eventpipeconfiguration.h"
   9 #include "eventpipeevent.h"
  10 #include "eventpipefile.h"
  11 #include "eventpipeprovider.h"
  12 #include "eventpipejsonfile.h"
  13 #include "sampleprofiler.h"
  14
  15 #ifdef FEATURE_PAL
  16 #include "pal.h"
  17 #endif // FEATURE_PAL
  18
  19 #ifdef FEATURE_PERFTRACING
  20
  21 CrstStatic EventPipe::s_configCrst;
  22 bool EventPipe::s_tracingInitialized = false;
  23 EventPipeConfiguration* EventPipe::s_pConfig = NULL;
  24 EventPipeBufferManager* EventPipe::s_pBufferManager = NULL;
  25 EventPipeFile* EventPipe::s_pFile = NULL;
  26 #ifdef _DEBUG
  27 EventPipeFile* EventPipe::s_pSyncFile = NULL;
  28 EventPipeJsonFile* EventPipe::s_pJsonFile = NULL;
  29 #endif // _DEBUG
  30
  31 #ifdef FEATURE_PAL
  32 // This function is auto-generated from /src/scripts/genEventPipe.py
  33 extern "C" void InitProvidersAndEvents();
  34 #endif
  35
  36 #ifdef FEATURE_PAL
  37 // This function is auto-generated from /src/scripts/genEventPipe.py
  38 extern "C" void InitProvidersAndEvents();
  39 #endif
  40
  41 void EventPipe::Initialize()
  42 {
  43     STANDARD_VM_CONTRACT;
  44
  45     s_tracingInitialized = s_configCrst.InitNoThrow(
  46         CrstEventPipe,
  47         (CrstFlags)(CRST_REENTRANCY | CRST_TAKEN_DURING_SHUTDOWN | CRST_HOST_BREAKABLE));
  48
  49     s_pConfig = new EventPipeConfiguration();
  50     s_pConfig->Initialize();
  51
  52     s_pBufferManager = new EventPipeBufferManager();
  53
  54 #ifdef FEATURE_PAL
  55     // This calls into auto-generated code to initialize the runtime providers
  56     // and events so that the EventPipe configuration lock isn't taken at runtime
  57     InitProvidersAndEvents();
  58 #endif
  59 }
  60
  61 void EventPipe::EnableOnStartup()
  62 {
  63     CONTRACTL
  64     {
  65         THROWS;
  66         GC_TRIGGERS;
  67         MODE_ANY;
  68     }
  69     CONTRACTL_END;
  70
  71     // Test COMPLUS variable to enable tracing at start-up.
  72     if((CLRConfig::GetConfigValue(CLRConfig::INTERNAL_PerformanceTracing) & 1) == 1)
  73     {
  74         SString outputPath;
  75         outputPath.Printf("Process-%d.netperf", GetCurrentProcessId());
  76         Enable(
  77             outputPath.GetUnicode(),
  78             1024 /* 1 GB circular buffer */,
  79             NULL /* pProviders */,
  80             0 /* numProviders */);
  81     }
  82 }
  83
  84 void EventPipe::Shutdown()
  85 {
  86     CONTRACTL
  87     {
  88         THROWS;
  89         GC_TRIGGERS;
  90         MODE_ANY;
  91     }
  92     CONTRACTL_END;
  93
  94     Disable();
  95
  96     if(s_pConfig != NULL)
  97     {
  98         delete(s_pConfig);
  99         s_pConfig = NULL;
 100     }
 101     if(s_pBufferManager != NULL)
 102     {
 103         delete(s_pBufferManager);
 104         s_pBufferManager = NULL;
 105     }
 106 }
 107
 108 void EventPipe::Enable(
 109     LPCWSTR strOutputPath,
 110     unsigned int circularBufferSizeInMB,
 111     EventPipeProviderConfiguration *pProviders,
 112     int numProviders)
 113 {
 114     CONTRACTL
 115     {
 116         THROWS;
 117         GC_TRIGGERS;
 118         MODE_ANY;
 119     }
 120     CONTRACTL_END;
 121
 122     // If tracing is not initialized or is already enabled, bail here.
 123     if(!s_tracingInitialized || s_pConfig->Enabled())
 124     {
 125         return;
 126     }
 127
 128     // Take the lock before enabling tracing.
 129     CrstHolder _crst(GetLock());
 130
 131     // Create the event pipe file.
 132     SString eventPipeFileOutputPath(strOutputPath);
 133     s_pFile = new EventPipeFile(eventPipeFileOutputPath);
 134
 135 #ifdef _DEBUG
 136     if((CLRConfig::GetConfigValue(CLRConfig::INTERNAL_PerformanceTracing) & 2) == 2)
 137     {
 138         // Create a synchronous file.
 139         SString eventPipeSyncFileOutputPath;
 140         eventPipeSyncFileOutputPath.Printf("Process-%d.sync.netperf", GetCurrentProcessId());
 141         s_pSyncFile = new EventPipeFile(eventPipeSyncFileOutputPath);
 142
 143         // Create a JSON file.
 144         SString outputFilePath;
 145         outputFilePath.Printf("Process-%d.PerfView.json", GetCurrentProcessId());
 146         s_pJsonFile = new EventPipeJsonFile(outputFilePath);
 147     }
 148 #endif // _DEBUG
 149
 150     // Enable tracing.
 151     s_pConfig->Enable(circularBufferSizeInMB, pProviders, numProviders);
 152
 153     // Enable the sample profiler
 154     SampleProfiler::Enable();
 155 }
 156
 157 void EventPipe::Disable()
 158 {
 159     CONTRACTL
 160     {
 161         THROWS;
 162         GC_TRIGGERS;
 163         MODE_ANY;
 164     }
 165     CONTRACTL_END;
 166
 167     // Don't block GC during clean-up.
 168     GCX_PREEMP();
 169
 170     // Take the lock before disabling tracing.
 171     CrstHolder _crst(GetLock());
 172
 173     if(s_pConfig->Enabled())
 174     {
 175         // Disable the profiler.
 176         SampleProfiler::Disable();
 177
 178         // Disable tracing.
 179         s_pConfig->Disable();
 180
 181         // Flush all write buffers to make sure that all threads see the change.
 182         FlushProcessWriteBuffers();
 183
 184         // Write to the file.
 185         LARGE_INTEGER disableTimeStamp;
 186         QueryPerformanceCounter(&disableTimeStamp);
 187         s_pBufferManager->WriteAllBuffersToFile(s_pFile, disableTimeStamp);
 188
 189         // Before closing the file, do rundown.
 190         s_pConfig->EnableRundown();
 191
 192         // Ask the runtime to emit rundown events.
 193         if(g_fEEStarted && !g_fEEShutDown)
 194         {
 195             ETW::EnumerationLog::EndRundown();
 196         }
 197
 198         // Disable the event pipe now that rundown is complete.
 199         s_pConfig->Disable();
 200
 201         if(s_pFile != NULL)
 202         {
 203             delete(s_pFile);
 204             s_pFile = NULL;
 205         }
 206 #ifdef _DEBUG
 207         if(s_pSyncFile != NULL)
 208         {
 209             delete(s_pSyncFile);
 210             s_pSyncFile = NULL;
 211         }
 212         if(s_pJsonFile != NULL)
 213         {
 214             delete(s_pJsonFile);
 215             s_pJsonFile = NULL;
 216         }
 217 #endif // _DEBUG
 218
 219         // De-allocate buffers.
 220         s_pBufferManager->DeAllocateBuffers();
 221
 222         // Delete deferred providers.
 223         // Providers can't be deleted during tracing because they may be needed when serializing the file.
 224         s_pConfig->DeleteDeferredProviders();
 225     }
 226 }
 227
 228 bool EventPipe::Enabled()
 229 {
 230     LIMITED_METHOD_CONTRACT;
 231
 232     bool enabled = false;
 233     if(s_pConfig != NULL)
 234     {
 235         enabled = s_pConfig->Enabled();
 236     }
 237
 238     return enabled;
 239 }
 240
 241 EventPipeProvider* EventPipe::CreateProvider(const GUID &providerID, EventPipeCallback pCallbackFunction, void *pCallbackData)
 242 {
 243     CONTRACTL
 244     {
 245         THROWS;
 246         GC_TRIGGERS;
 247         MODE_ANY;
 248     }
 249     CONTRACTL_END;
 250
 251     return new EventPipeProvider(providerID, pCallbackFunction, pCallbackData);
 252 }
 253
 254 void EventPipe::DeleteProvider(EventPipeProvider *pProvider)
 255 {
 256     CONTRACTL
 257     {
 258         THROWS;
 259         GC_TRIGGERS;
 260         MODE_ANY;
 261     }
 262     CONTRACTL_END;
 263
 264     // Take the lock to make sure that we don't have a race
 265     // between disabling tracing and deleting a provider
 266     // where we hold a provider after tracing has been disabled.
 267     CrstHolder _crst(GetLock());
 268
 269     if(pProvider != NULL)
 270     {
 271         if(Enabled())
 272         {
 273             // Save the provider until the end of the tracing session.
 274             pProvider->SetDeleteDeferred();
 275         }
 276         else
 277         {
 278             // Delete the provider now.
 279             // NOTE: This will remove it from all of the EventPipe data structures.
 280             delete(pProvider);
 281         }
 282     }
 283 }
 284
 285 void EventPipe::WriteEvent(EventPipeEvent &event, BYTE *pData, unsigned int length, LPCGUID pActivityId, LPCGUID pRelatedActivityId)
 286 {
 287     CONTRACTL
 288     {
 289         NOTHROW;
 290         GC_NOTRIGGER;
 291         MODE_ANY;
 292         PRECONDITION(s_pBufferManager != NULL);
 293     }
 294     CONTRACTL_END;
 295
 296     // Exit early if the event is not enabled.
 297     if(!event.IsEnabled())
 298     {
 299         return;
 300     }
 301
 302     // Get the current thread;
 303     Thread *pThread = GetThread();
 304     if(pThread == NULL)
 305     {
 306         // We can't write an event without the thread object.
 307         return;
 308     }
 309
 310     if(!s_pConfig->RundownEnabled() && s_pBufferManager != NULL)
 311     {
 312         if(!s_pBufferManager->WriteEvent(pThread, event, pData, length, pActivityId, pRelatedActivityId))
 313         {
 314             // This is used in DEBUG to make sure that we don't log an event synchronously that we didn't log to the buffer.
 315             return;
 316         }
 317     }
 318     else if(s_pConfig->RundownEnabled())
 319     {
 320         // Write synchronously to the file.
 321         // We're under lock and blocking the disabling thread.
 322         EventPipeEventInstance instance(
 323             event,
 324             pThread->GetOSThreadId(),
 325             pData,
 326             length,
 327             pActivityId,
 328             pRelatedActivityId);
 329
 330         if(s_pFile != NULL)
 331         {
 332             s_pFile->WriteEvent(instance);
 333         }
 334     }
 335
 336 #ifdef _DEBUG
 337     {
 338         GCX_PREEMP();
 339
 340         // Create an instance of the event for the synchronous path.
 341         EventPipeEventInstance instance(
 342             event,
 343             pThread->GetOSThreadId(),
 344             pData,
 345             length,
 346             pActivityId,
 347             pRelatedActivityId);
 348
 349         // Write to the EventPipeFile if it exists.
 350         if(s_pSyncFile != NULL)
 351         {
 352             s_pSyncFile->WriteEvent(instance);
 353         }
 354
 355         // Write to the EventPipeJsonFile if it exists.
 356         if(s_pJsonFile != NULL)
 357         {
 358             s_pJsonFile->WriteEvent(instance);
 359         }
 360     }
 361 #endif // _DEBUG
 362 }
 363
 364 void EventPipe::WriteSampleProfileEvent(Thread *pSamplingThread, EventPipeEvent *pEvent, Thread *pTargetThread, StackContents &stackContents, BYTE *pData, unsigned int length)
 365 {
 366     CONTRACTL
 367     {
 368         NOTHROW;
 369         GC_TRIGGERS;
 370         MODE_PREEMPTIVE;
 371     }
 372     CONTRACTL_END;
 373
 374     // Write the event to the thread's buffer.
 375     if(s_pBufferManager != NULL)
 376     {
 377         // Specify the sampling thread as the "current thread", so that we select the right buffer.
 378         // Specify the target thread so that the event gets properly attributed.
 379         if(!s_pBufferManager->WriteEvent(pSamplingThread, *pEvent, pData, length, NULL /* pActivityId */, NULL /* pRelatedActivityId */, pTargetThread, &stackContents))
 380         {
 381             // This is used in DEBUG to make sure that we don't log an event synchronously that we didn't log to the buffer.
 382             return;
 383         }
 384     }
 385
 386 #ifdef _DEBUG
 387     {
 388         GCX_PREEMP();
 389
 390         // Create an instance for the synchronous path.
 391         SampleProfilerEventInstance instance(*pEvent, pTargetThread, pData, length);
 392         stackContents.CopyTo(instance.GetStack());
 393
 394         // Write to the EventPipeFile.
 395         if(s_pSyncFile != NULL)
 396         {
 397             s_pSyncFile->WriteEvent(instance);
 398         }
 399
 400         // Write to the EventPipeJsonFile if it exists.
 401         if(s_pJsonFile != NULL)
 402         {
 403             s_pJsonFile->WriteEvent(instance);
 404         }
 405     }
 406 #endif // _DEBUG
 407 }
 408
 409 bool EventPipe::WalkManagedStackForCurrentThread(StackContents &stackContents)
 410 {
 411     CONTRACTL
 412     {
 413         NOTHROW;
 414         GC_NOTRIGGER;
 415         MODE_ANY;
 416     }
 417     CONTRACTL_END;
 418
 419     Thread *pThread = GetThread();
 420     if(pThread != NULL)
 421     {
 422         return WalkManagedStackForThread(pThread, stackContents);
 423     }
 424
 425     return false;
 426 }
 427
 428 bool EventPipe::WalkManagedStackForThread(Thread *pThread, StackContents &stackContents)
 429 {
 430     CONTRACTL
 431     {
 432         NOTHROW;
 433         GC_NOTRIGGER;
 434         MODE_ANY;
 435         PRECONDITION(pThread != NULL);
 436     }
 437     CONTRACTL_END;
 438
 439     stackContents.Reset();
 440
 441     StackWalkAction swaRet = pThread->StackWalkFrames(
 442         (PSTACKWALKFRAMESCALLBACK) &StackWalkCallback,
 443         &stackContents,
 444         ALLOW_ASYNC_STACK_WALK | FUNCTIONSONLY | HANDLESKIPPEDFRAMES);
 445
 446     return ((swaRet == SWA_DONE) || (swaRet == SWA_CONTINUE));
 447 }
 448
 449 StackWalkAction EventPipe::StackWalkCallback(CrawlFrame *pCf, StackContents *pData)
 450 {
 451     CONTRACTL
 452     {
 453         NOTHROW;
 454         GC_NOTRIGGER;
 455         MODE_PREEMPTIVE;
 456         PRECONDITION(pCf != NULL);
 457         PRECONDITION(pData != NULL);
 458     }
 459     CONTRACTL_END;
 460
 461     // Get the IP.
 462     UINT_PTR controlPC = (UINT_PTR)pCf->GetRegisterSet()->ControlPC;
 463     if(controlPC == 0)
 464     {
 465         if(pData->GetLength() == 0)
 466         {
 467             // This happens for pinvoke stubs on the top of the stack.
 468             return SWA_CONTINUE;
 469         }
 470     }
 471
 472     _ASSERTE(controlPC != 0);
 473
 474     // Add the IP to the captured stack.
 475     pData->Append(
 476         controlPC,
 477         pCf->GetFunction()
 478         );
 479
 480     // Continue the stack walk.
 481     return SWA_CONTINUE;
 482 }
 483
 484 EventPipeConfiguration* EventPipe::GetConfiguration()
 485 {
 486     LIMITED_METHOD_CONTRACT;
 487
 488     return s_pConfig;
 489 }
 490
 491 CrstStatic* EventPipe::GetLock()
 492 {
 493     LIMITED_METHOD_CONTRACT;
 494
 495     return &s_configCrst;
 496 }
 497
 498 void QCALLTYPE EventPipeInternal::Enable(
 499         __in_z LPCWSTR outputFile,
 500         unsigned int circularBufferSizeInMB,
 501         long profilerSamplingRateInNanoseconds,
 502         EventPipeProviderConfiguration *pProviders,
 503         int numProviders)
 504 {
 505     QCALL_CONTRACT;
 506
 507     BEGIN_QCALL;
 508     SampleProfiler::SetSamplingRate(profilerSamplingRateInNanoseconds);
 509     EventPipe::Enable(outputFile, circularBufferSizeInMB, pProviders, numProviders);
 510     END_QCALL;
 511 }
 512
 513 void QCALLTYPE EventPipeInternal::Disable()
 514 {
 515     QCALL_CONTRACT;
 516
 517     BEGIN_QCALL;
 518     EventPipe::Disable();
 519     END_QCALL;
 520 }
 521
 522 INT_PTR QCALLTYPE EventPipeInternal::CreateProvider(
 523     GUID providerID,
 524     EventPipeCallback pCallbackFunc)
 525 {
 526     QCALL_CONTRACT;
 527
 528     EventPipeProvider *pProvider = NULL;
 529
 530     BEGIN_QCALL;
 531
 532     pProvider = EventPipe::CreateProvider(providerID, pCallbackFunc, NULL);
 533
 534     END_QCALL;
 535
 536     return reinterpret_cast<INT_PTR>(pProvider);
 537 }
 538
 539 INT_PTR QCALLTYPE EventPipeInternal::DefineEvent(
 540     INT_PTR provHandle,
 541     unsigned int eventID,
 542     __int64 keywords,
 543     unsigned int eventVersion,
 544     unsigned int level,
 545     void *pMetadata,
 546     unsigned int metadataLength)
 547 {
 548     QCALL_CONTRACT;
 549
 550     EventPipeEvent *pEvent = NULL;
 551
 552     BEGIN_QCALL;
 553
 554     _ASSERTE(provHandle != NULL);
 555     _ASSERTE(pMetadata != NULL);
 556     EventPipeProvider *pProvider = reinterpret_cast<EventPipeProvider *>(provHandle);
 557     pEvent = pProvider->AddEvent(eventID, keywords, eventVersion, (EventPipeEventLevel)level, (BYTE *)pMetadata, metadataLength);
 558     _ASSERTE(pEvent != NULL);
 559
 560     END_QCALL;
 561
 562     return reinterpret_cast<INT_PTR>(pEvent);
 563 }
 564
 565 void QCALLTYPE EventPipeInternal::DeleteProvider(
 566     INT_PTR provHandle)
 567 {
 568     QCALL_CONTRACT;
 569     BEGIN_QCALL;
 570
 571     if(provHandle != NULL)
 572     {
 573         EventPipeProvider *pProvider = reinterpret_cast<EventPipeProvider*>(provHandle);
 574         EventPipe::DeleteProvider(pProvider);
 575     }
 576
 577     END_QCALL;
 578 }
 579
 580 void QCALLTYPE EventPipeInternal::WriteEvent(
 581     INT_PTR eventHandle,
 582     unsigned int eventID,
 583     void *pData,
 584     unsigned int length,
 585     LPCGUID pActivityId,
 586     LPCGUID pRelatedActivityId)
 587 {
 588     QCALL_CONTRACT;
 589     BEGIN_QCALL;
 590
 591     _ASSERTE(eventHandle != NULL);
 592     EventPipeEvent *pEvent = reinterpret_cast<EventPipeEvent *>(eventHandle);
 593     EventPipe::WriteEvent(*pEvent, (BYTE *)pData, length, pActivityId, pRelatedActivityId);
 594
 595     END_QCALL;
 596 }
 597
 598 #endif // FEATURE_PERFTRACING