[Profiler] Allow tests for .NET Framework

Datadog.Profiler.sln

@@ -122,6 +122,10 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Demos", "Demos", "{EACEAEE9
  profiler\src\Demos\Directory.Build.props = profiler\src\Demos\Directory.Build.props
  EndProjectSection
 EndProject
+Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "dd-prof-etw-replay", "profiler\src\Tools\ETW\dd-prof-etw\dd-prof-etw-replay\dd-prof-etw-replay.csproj", "{837CD3F8-08E9-4952-9834-5179B60242DD}"
+EndProject
+Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "dd-prof-etw-agent", "profiler\src\Tools\ETW\dd-prof-etw\dd-prof-etw-agent\dd-prof-etw-agent.csproj", "{B9662E54-7FE8-4199-B98F-3125E0D9F225}"
+EndProject
 Global
  GlobalSection(SolutionConfigurationPlatforms) = preSolution
  Debug|Any CPU = Debug|Any CPU
@@ -542,6 +546,38 @@ Global
  {97DD3E31-0922-455E-A308-E0C798E84476}.Release|x64.Build.0 = Release|x64
  {97DD3E31-0922-455E-A308-E0C798E84476}.Release|x86.ActiveCfg = Release|Win32
  {97DD3E31-0922-455E-A308-E0C798E84476}.Release|x86.Build.0 = Release|Win32
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|Any CPU.Build.0 = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|ARM64.ActiveCfg = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|ARM64.Build.0 = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|x64.ActiveCfg = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|x64.Build.0 = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|x86.ActiveCfg = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Debug|x86.Build.0 = Debug|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|Any CPU.ActiveCfg = Release|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|Any CPU.Build.0 = Release|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|ARM64.ActiveCfg = Release|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|ARM64.Build.0 = Release|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|x64.ActiveCfg = Release|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|x64.Build.0 = Release|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|x86.ActiveCfg = Release|Any CPU
+ {837CD3F8-08E9-4952-9834-5179B60242DD}.Release|x86.Build.0 = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|Any CPU.Build.0 = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|ARM64.ActiveCfg = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|ARM64.Build.0 = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|x64.ActiveCfg = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|x64.Build.0 = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|x86.ActiveCfg = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Debug|x86.Build.0 = Debug|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|Any CPU.ActiveCfg = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|Any CPU.Build.0 = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|ARM64.ActiveCfg = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|ARM64.Build.0 = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|x64.ActiveCfg = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|x64.Build.0 = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|x86.ActiveCfg = Release|Any CPU
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225}.Release|x86.Build.0 = Release|Any CPU
  EndGlobalSection
  GlobalSection(SolutionProperties) = preSolution
  HideSolutionNode = FALSE
@@ -586,6 +622,8 @@ Global
  {97DD3E31-0922-455E-A308-E0C798E84476} = {C1D06C89-E4D1-4E09-9AB6-35BB5A1DEB04}
  {C1D06C89-E4D1-4E09-9AB6-35BB5A1DEB04} = {D2476213-2D12-43A8-966C-BCFCE098FD63}
  {EACEAEE9-23A6-448F-A56E-39FE4E837FA6} = {3437D742-5FB6-4457-8291-1EBBADBEE1BC}
+ {837CD3F8-08E9-4952-9834-5179B60242DD} = {C1D06C89-E4D1-4E09-9AB6-35BB5A1DEB04}
+ {B9662E54-7FE8-4199-B98F-3125E0D9F225} = {C1D06C89-E4D1-4E09-9AB6-35BB5A1DEB04}
  EndGlobalSection
  GlobalSection(ExtensibilityGlobals) = postSolution
  SolutionGuid = {917C242A-028D-42FD-BA47-E7317B6A36B4}

profiler/src/Demos/Samples.BuggyBits/Controllers/NewsController.cs

@@ -12,15 +12,14 @@
 
 namespace BuggyBits.Controllers
 {
-
  public class NewsController : Controller
  {
  private static int _id = 0;
  private int _instanceId;
 
-//#pragma warning disable IDE0052 // Remove unread private members | this field is used to better show memory leaks
+// #pragma warning disable IDE0052 // Remove unread private members | this field is used to better show memory leaks
 // private readonly int[] bits = new int[25000];
-//#pragma warning restore IDE0052
+// #pragma warning restore IDE0052
  private IMemoryCache cache;
  private DateTime _creationTime;
 
@@ -34,17 +33,17 @@ public NewsController(IMemoryCache cache)
 
  ~NewsController()
  {
- Console.WriteLine($"{DateTime.Now.ToShortTimeString()} | {(DateTime.Now -_creationTime).TotalSeconds, 4} - ~NewsController #{_instanceId}");
+ Console.WriteLine($"{DateTime.Now.ToShortTimeString()} | {(DateTime.Now - _creationTime).TotalSeconds,4} - ~NewsController #{_instanceId}");
  }
 
  public IActionResult Index()
  {
  string key = Guid.NewGuid().ToString();
  var cachedResult = cache.GetOrCreate(key, cacheEntry =>
  {
- ////Adding a sliding expiration will help to evict cache entries sooner
- ////but the LOH will become fragmented
- //cacheEntry.SlidingExpiration = TimeSpan.FromMinutes(5);
+ //// Adding a sliding expiration will help to evict cache entries sooner
+ //// but the LOH will become fragmented
+ // cacheEntry.SlidingExpiration = TimeSpan.FromMinutes(5);
 
  cacheEntry.RegisterPostEvictionCallback(CacheRemovedCallback);
  cacheEntry.Priority = CacheItemPriority.NeverRemove;

profiler/src/Demos/Samples.BuggyBits/SelfInvoker.cs

@@ -115,7 +115,6 @@ private void StartThreadsForLeaks(string rootUrl, int iterations)
  await Task.Delay(TimeSpan.FromMilliseconds(1000 + delay.TotalMilliseconds));
  current++;
  }
-
  },
  creationOptions: TaskCreationOptions.LongRunning);
  }

profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.cpp

@@ -13,35 +13,45 @@
 EtwEventsHandler::EtwEventsHandler()
  :
  _showMessages {false},
- _pReceiver {nullptr}
+ _pReceiver {nullptr},
+ _pEventsFile {nullptr},
+ _logger {nullptr}
 {
 }
 
-EtwEventsHandler::EtwEventsHandler(IIpcLogger* logger, IEtwEventsReceiver* pClrEventsReceiver)
+EtwEventsHandler::EtwEventsHandler(IIpcLogger* logger, IEtwEventsReceiver* pClrEventsReceiver, FILE* pEventsFile)
  :
  _logger {logger},
- _pReceiver {pClrEventsReceiver}
+ _showMessages {false},
+ _pReceiver {pClrEventsReceiver},
+ _pEventsFile {pEventsFile}
 {
 }
 
 EtwEventsHandler::~EtwEventsHandler()
 {
- Stop();
+ Cleanup();
 }
 
-void EtwEventsHandler::Stop()
+void EtwEventsHandler::Cleanup()
 {
+ if (_pEventsFile != nullptr)
+ {
+ fclose(_pEventsFile);
+ _pEventsFile = nullptr;
+ }
+
  _stopRequested.store(true);
 }
 
 void EtwEventsHandler::OnStartError()
 {
- Stop();
+ Cleanup();
 }
 
 void EtwEventsHandler::OnConnectError()
 {
- Stop();
+ Cleanup();
 }
 
 void EtwEventsHandler::WriteSuccessResponse(HANDLE hPipe)
@@ -60,6 +70,7 @@ void EtwEventsHandler::OnConnect(HANDLE hPipe)
  auto message = reinterpret_cast<ClrEventsMessage*>(buffer.get());
 
  DWORD readSize;
+ DWORD eventsCount = 0;
  while (!_stopRequested.load())
  {
  readSize = 0;
@@ -69,6 +80,15 @@ void EtwEventsHandler::OnConnect(HANDLE hPipe)
  break;
  }
 
+ // serialize the event to file if needed
+ if (_pEventsFile != nullptr)
+ {
+ fwrite(buffer.get(), sizeof(uint8_t), readSize, _pEventsFile);
+ std::stringstream builder;
+ builder << "Read size = " << readSize << " bytes -- Message size = " << message->Size << " | Event payload size = " << message->Payload.EtwUserDataLength;
+ _logger->Info(builder.str());
+ }
+
  // check the message based on the expected command
  if (message->CommandId == Commands::IsAlive)
  {
@@ -87,6 +107,8 @@ void EtwEventsHandler::OnConnect(HANDLE hPipe)
  continue;
  }
 
+ eventsCount++;
+
  const EVENT_HEADER* pHeader = &(message->EtwHeader);
  uint32_t tid = pHeader->ThreadId;
  uint8_t version = pHeader->EventDescriptor.Version;
@@ -107,6 +129,10 @@ void EtwEventsHandler::OnConnect(HANDLE hPipe)
  if (_pReceiver != nullptr)
  {
  _pReceiver->OnEvent(timestamp, tid, version, keyword, level, id, userDataLength, pUserData);
+
+ std::stringstream builder;
+ builder << "ETW event #" << eventsCount << " | " << keyword << " - " << id;
+ _logger->Info(builder.str());
  }
 
  // fire and forget so no need to answer
@@ -123,6 +149,9 @@ void EtwEventsHandler::OnConnect(HANDLE hPipe)
  break;
  }
  }
+
+ // close the event file if needed
+ Cleanup();
 }
 
 bool EtwEventsHandler::ReadEvents(HANDLE hPipe, uint8_t* pBuffer, DWORD bufferSize, DWORD& readSize)

profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.h

@@ -5,6 +5,7 @@
 
 #include <atomic>
 #include <memory>
+#include "stdio.h"
 #include <string>
 #include <unordered_map>
 #include <vector>
@@ -19,9 +20,9 @@ class EtwEventsHandler : public INamedPipeHandler
 {
 public:
  EtwEventsHandler();
- EtwEventsHandler(IIpcLogger* logger, IEtwEventsReceiver* pClrEventsReceiver);
+ EtwEventsHandler(IIpcLogger* logger, IEtwEventsReceiver* pClrEventsReceiver, FILE* pEventsFile);
  ~EtwEventsHandler();
- void Stop();
+ void Cleanup();
 
 public:
 // Inherited via INamedPipeHandler
@@ -38,4 +39,5 @@ class EtwEventsHandler : public INamedPipeHandler
  bool _showMessages;
  IEtwEventsReceiver* _pReceiver;
  IIpcLogger* _logger;
+ FILE* _pEventsFile;
 };

profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcClient.cpp

@@ -50,6 +50,12 @@ std::unique_ptr<IpcClient> IpcClient::Connect(IIpcLogger* pLogger, const std::st
  return nullptr;
  }
 
+ if (pLogger != nullptr)
+ {
+ std::ostringstream builder;
+ builder << "Pipe to " << portName << " has been created";
+ pLogger->Info(builder.str());
+ }
  return std::make_unique<IpcClient>(pLogger, hPipe);
  }
 
@@ -61,7 +67,9 @@ uint32_t IpcClient::Send(PVOID pBuffer, uint32_t bufferSize)
  auto lastError = ShowLastError("Failed to write to pipe");
  return lastError;
  }
- ::FlushFileBuffers(_hPipe);
+
+ // this might hang
+ //::FlushFileBuffers(_hPipe);
 
  return (bufferSize == writtenSize) ? NamedPipesCode::Success : NamedPipesCode::MissingData;
  }
@@ -99,14 +107,32 @@ uint32_t IpcClient::Read(PVOID pBuffer, uint32_t bufferSize)
 
 HANDLE IpcClient::GetEndPoint(IIpcLogger* pLogger, const std::string& portName, uint16_t timeoutMS)
 {
- bool success = ::WaitNamedPipeA(portName.c_str(), timeoutMS);
+ if (pLogger != nullptr)
+ {
+ std::ostringstream builder;
+ builder << "Waiting for " << portName << " endpoint...";
+ pLogger->Info(builder.str());
+ }
+
+ auto success = ::WaitNamedPipeA(portName.c_str(), timeoutMS);
  if (!success)
  {
  if (pLogger != nullptr)
  {
+ auto error = ::GetLastError();
  std::ostringstream builder;
- builder << "Timeout when trying to connect to" << portName << "...";
+ builder << "WaitNamedPipe(" << portName << ") failed with error " << error;
+ pLogger->Error(builder.str());
  }
+
+ return INVALID_HANDLE_VALUE;
+ }
+
+ if (pLogger != nullptr)
+ {
+ std::ostringstream builder;
+ builder << "Opening " << portName << " pipe...";
+ pLogger->Info(builder.str());
  }
 
  HANDLE hPipe = ::CreateFileA(
@@ -115,7 +141,7 @@ HANDLE IpcClient::GetEndPoint(IIpcLogger* pLogger, const std::string& portName,
  0,
  nullptr,
  OPEN_EXISTING,
- 0,
+ FILE_FLAG_NO_BUFFERING | FILE_FLAG_WRITE_THROUGH,
  nullptr);
 
  return hPipe;

profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcServer.cpp

@@ -43,7 +43,7 @@ void IpcServer::Stop()
  0,
  nullptr,
  OPEN_EXISTING,
- 0,
+ FILE_FLAG_NO_BUFFERING | FILE_FLAG_WRITE_THROUGH,
  nullptr);
  if (hPipe != INVALID_HANDLE_VALUE)
  {