diff --git a/Datadog.Profiler.sln b/Datadog.Profiler.sln index 1927267d2bcf..4de199198899 100644 --- a/Datadog.Profiler.sln +++ b/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} diff --git a/profiler/src/Demos/Samples.BuggyBits/Controllers/NewsController.cs b/profiler/src/Demos/Samples.BuggyBits/Controllers/NewsController.cs index 677b1cfdcb44..b001938d8939 100644 --- a/profiler/src/Demos/Samples.BuggyBits/Controllers/NewsController.cs +++ b/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,7 +33,7 @@ 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() @@ -42,9 +41,9 @@ 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; diff --git a/profiler/src/Demos/Samples.BuggyBits/SelfInvoker.cs b/profiler/src/Demos/Samples.BuggyBits/SelfInvoker.cs index 34a098e7d5a4..b2c935e04e87 100644 --- a/profiler/src/Demos/Samples.BuggyBits/SelfInvoker.cs +++ b/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); } diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.cpp index 1aca4386b7de..6f4a80ef22c8 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.cpp +++ b/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(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) diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.h b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.h index e1d6755b2a52..447d7a3a4883 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.h +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/EtwEventsHandler.h @@ -5,6 +5,7 @@ #include #include +#include "stdio.h" #include #include #include @@ -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; }; \ No newline at end of file diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcClient.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcClient.cpp index b544b99b8da8..8c964c8c23f9 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcClient.cpp +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcClient.cpp @@ -50,6 +50,12 @@ std::unique_ptr 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(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; diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcServer.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcServer.cpp index 5cfb72a7be76..b6826bb1d08a 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/ETW/IpcServer.cpp +++ b/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) { diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.cpp index fdae1266fccd..e50f6c205657 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.cpp +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.cpp @@ -3,6 +3,7 @@ #include "EtwEventsManager.h" +#include "FrameStore.h" #include "IContentionListener.h" #include "IAllocationsListener.h" #include "IGCSuspensionsListener.h" @@ -31,7 +32,7 @@ EtwEventsManager::EtwEventsManager( _pContentionListener(pContentionListener) { _isDebugLogEnabled = pConfiguration->IsEtwLoggingEnabled(); - + _agentReplayEndpoint = pConfiguration->GetEtwReplayEndpoint(); _threadsInfo.reserve(256); _parser = std::make_unique( nullptr, // to avoid duplicates with what is done in EtwEventsHandler @@ -202,21 +203,32 @@ void EtwEventsManager::OnEvent( // // // - // + // // !! the following 2 fields cannot be directly accessed because // !! they will be stored after the string TypeName // // // but no object size... // Since the events are received asynchronously, it is not even possible - // to assume that the object that was stored at the received Adress field + // to assume that the object that was stored at the received Adress field // is still there: it could have been moved by a garbage collection AllocationTickV3Payload* pPayload = (AllocationTickV3Payload*)pEventData; pThreadInfo->AllocationTickTimestamp = timestamp; pThreadInfo->AllocationKind = pPayload->AllocationKind; - pThreadInfo->AllocationClassId = (uintptr_t)pPayload->TypeId; + + // when events are replayed, no pointer value should be used + // --> ClassID is invalid and should not be used + if (!_agentReplayEndpoint.empty()) + { + pThreadInfo->AllocationClassId = 0; + } + else + { + pThreadInfo->AllocationClassId = (uintptr_t)pPayload->TypeId; + } + pThreadInfo->AllocationAmount = pPayload->AllocationAmount64; - + // TODO: should we use a buffer allocated once and reused to avoid memory allocations due to std::string? pThreadInfo->AllocatedType = shared::ToString(shared::WSTRING(&(pPayload->FirstCharInName))); @@ -294,14 +306,32 @@ void EtwEventsManager::AttachCallstack(std::vector& stack, uint16_t u } } +// In case of tests, a custom endpoint can be used to avoid the need of the Datadog Agent +// and the received IPs are not valid --> we need to use a fake one void EtwEventsManager::AttachContentionCallstack(ThreadInfo* pThreadInfo, uint16_t userDataLength, const uint8_t* pUserData) { - AttachCallstack(pThreadInfo->ContentionCallStack, userDataLength, pUserData); + if (_agentReplayEndpoint.empty()) + { + AttachCallstack(pThreadInfo->ContentionCallStack, userDataLength, pUserData); + } + else + { + pThreadInfo->ContentionCallStack.clear(); + pThreadInfo->ContentionCallStack.push_back(FrameStore::FakeLockContentionIP); + } } void EtwEventsManager::AttachAllocationCallstack(ThreadInfo* pThreadInfo, uint16_t userDataLength, const uint8_t* pUserData) { - AttachCallstack(pThreadInfo->AllocationCallStack, userDataLength, pUserData); + if (_agentReplayEndpoint.empty()) + { + AttachCallstack(pThreadInfo->AllocationCallStack, userDataLength, pUserData); + } + else + { + pThreadInfo->AllocationCallStack.clear(); + pThreadInfo->AllocationCallStack.push_back(FrameStore::FakeAllocationIP); + } } void EtwEventsManager::OnStop() @@ -323,9 +353,10 @@ bool EtwEventsManager::Start() buffer << NamedPipePrefix; buffer << pid; std::string pipeName = buffer.str(); + Log::Info("Exposing ", pipeName); - _eventsHandler = std::make_unique(_logger.get(), this); + _eventsHandler = std::make_unique(_logger.get(), this, nullptr); _IpcServer = IpcServer::StartAsync( _logger.get(), pipeName, @@ -341,7 +372,7 @@ bool EtwEventsManager::Start() } // create the client part to send the registration command - pipeName = NamedPipeAgent; + pipeName = (_agentReplayEndpoint.empty()) ? NamedPipeAgent : _agentReplayEndpoint; Log::Info("Contacting ", pipeName, "..."); _IpcClient = IpcClient::Connect(_logger.get(), pipeName, TimeoutMS); @@ -410,12 +441,14 @@ bool EtwEventsManager::SendRegistrationCommand(bool add) SetupUnregisterCommand(message, pid); } + Log::Info("Sending command to the Datadog Agent..."); auto code = pClient->Send(&message, sizeof(message)); if (code != NamedPipesCode::Success) { LogLastError("Failed to write to pipe", code); return false; } + Log::Info("Command sent to the Datadog Agent"); IpcHeader response; code = pClient->Read(&response, sizeof(response)); diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.h b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.h index c2a71791a9e9..8134d1b09862 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.h +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.h @@ -110,6 +110,7 @@ class EtwEventsManager : // responsible for receiving ETW events from the Windows Agent std::unique_ptr _eventsHandler; + std::string _agentReplayEndpoint; std::unique_ptr _IpcServer; // used to connect to the Windows Agent and register our process ID std::unique_ptr _IpcClient; // used to receive ETW events from the Windows Agent diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/AllocationsProvider.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/AllocationsProvider.cpp index c807ac4fd482..98b65c8f5056 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/AllocationsProvider.cpp +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/AllocationsProvider.cpp @@ -146,10 +146,11 @@ void AllocationsProvider::OnAllocation(uint32_t allocationKind, rawSample.Address = address; rawSample.MethodTable = classId; - // The provided type name contains the metadata-based `xx syntax for generics instead of <> - // So rely on the frame store to get a C#-like representation like what is done for frames - if (!_pFrameStore->GetTypeName(classId, rawSample.AllocationClass)) + // the classID can be null when events are replayed in integration tests + if ((classId == 0) || !_pFrameStore->GetTypeName(classId, rawSample.AllocationClass)) { + // The provided type name contains the metadata-based `xx syntax for generics instead of <> + // So rely on the frame store to get a C#-like representation like what is done for frames rawSample.AllocationClass = shared::ToString(shared::WSTRING(typeName)); } diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.cpp index 1dd9bb276b10..de36b3eb3aac 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.cpp +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.cpp @@ -319,6 +319,10 @@ void ClrEventsParser::NotifyGarbageCollectionStarted(uint64_t timestamp, int32_t { for (auto& pGarbageCollectionsListener : _pGarbageCollectionsListeners) { + std::stringstream buffer; + buffer << "OnGarbageCollectionStart: " << number << " " << generation << " " << reason << " " << type; + LOG_GC_EVENT(buffer.str()); + pGarbageCollectionsListener->OnGarbageCollectionStart(timestamp, number, generation, reason, type); } } @@ -339,6 +343,10 @@ void ClrEventsParser::NotifyGarbageCollectionEnd( { for (auto& pGarbageCollectionsListener : _pGarbageCollectionsListeners) { + std::stringstream buffer; + buffer << "OnGarbageCollectionEnd: " << number << " " << generation << " " << reason << " " << type; + LOG_GC_EVENT(buffer.str()); + pGarbageCollectionsListener->OnGarbageCollectionEnd( number, generation, diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.h b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.h index 7140dd218bb0..fafe9e8866ce 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.h +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.h @@ -247,7 +247,7 @@ class ClrEventsParser // is only valid (different from 0) in the asynchronous scenario. // As of today, only the GC related events could be received asynchronously. // - // Lock contention and AllocationTick qre synchronous only here. + // Lock contention and AllocationTick are synchronous only here. // void ParseEvent( uint64_t timestamp, diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.cpp index 99302448f317..3e6c88c1e4c2 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.cpp +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.cpp @@ -93,6 +93,7 @@ Configuration::Configuration() _isEtwEnabled = GetEnvironmentValue(EnvironmentVariables::EtwEnabled, false); _deploymentMode = GetEnvironmentValue(EnvironmentVariables::SsiDeployed, DeploymentMode::Manual); _isEtwLoggingEnabled = GetEnvironmentValue(EnvironmentVariables::EtwLoggingEnabled, false); + _etwReplayEndpoint = GetEnvironmentValue(EnvironmentVariables::EtwReplayEndpoint, DefaultEmptyString); _enablementStatus = ExtractEnablementStatus(); _ssiLongLivedThreshold = ExtractSsiLongLivedThreshold(); _isTelemetryToDiskEnabled = GetEnvironmentValue(EnvironmentVariables::TelemetryToDiskEnabled, false); @@ -565,6 +566,15 @@ bool Configuration::IsEtwLoggingEnabled() const #endif } +std::string const& Configuration::GetEtwReplayEndpoint() const +{ +#ifdef LINUX + return DefaultEmptyString; +#else + return _etwReplayEndpoint; +#endif +} + EnablementStatus Configuration::GetEnablementStatus() const { return _enablementStatus; diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.h b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.h index 589e80ed2129..6f388654b377 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.h +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/Configuration.h @@ -73,6 +73,7 @@ class Configuration final : public IConfiguration std::uint64_t GetCIVisibilitySpanId() const override; bool IsEtwEnabled() const override; bool IsEtwLoggingEnabled() const override; + std::string const& GetEtwReplayEndpoint() const override; EnablementStatus GetEnablementStatus() const override; DeploymentMode GetDeploymentMode() const override; std::chrono::milliseconds GetSsiLongLivedThreshold() const override; @@ -169,6 +170,7 @@ class Configuration final : public IConfiguration bool _isEtwEnabled; DeploymentMode _deploymentMode; bool _isEtwLoggingEnabled; + std::string _etwReplayEndpoint; EnablementStatus _enablementStatus; std::chrono::milliseconds _ssiLongLivedThreshold; bool _isTelemetryToDiskEnabled; diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/EnvironmentVariables.h b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/EnvironmentVariables.h index 42d155222276..eb5411843d30 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/EnvironmentVariables.h +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/EnvironmentVariables.h @@ -63,6 +63,7 @@ class EnvironmentVariables final inline static const shared::WSTRING EtwEnabled = WStr("DD_INTERNAL_PROFILING_ETW_ENABLED"); inline static const shared::WSTRING SsiDeployed = WStr("DD_INJECTION_ENABLED"); inline static const shared::WSTRING EtwLoggingEnabled = WStr("DD_INTERNAL_ETW_LOGGING_ENABLED"); + inline static const shared::WSTRING EtwReplayEndpoint = WStr("DD_INTERNAL_ETW_REPLAY_ENDPOINT"); inline static const shared::WSTRING CpuProfilerType = WStr("DD_INTERNAL_CPU_PROFILER_TYPE"); inline static const shared::WSTRING CpuProfilingInterval = WStr("DD_INTERNAL_CPU_PROFILING_INTERVAL"); inline static const shared::WSTRING SsiLongLivedThreshold = WStr("DD_INTERNAL_PROFILING_LONG_LIVED_THRESHOLD"); diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.cpp b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.cpp index 61aff65e7c3f..874c565b4a18 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.cpp +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.cpp @@ -29,7 +29,6 @@ FrameStore::FrameStore(ICorProfilerInfo4* pCorProfilerInfo, IConfiguration* pCon { } - std::optional> FrameStore::GetFunctionFromIP(uintptr_t instructionPointer) { HRESULT hr; @@ -67,6 +66,30 @@ std::pair FrameStore::GetFrame(uintptr_t instructionPointer static const std::string NotResolvedModuleName("NotResolvedModule"); static const std::string NotResolvedFrame("NotResolvedFrame"); static const std::string UnloadedModuleName("UnloadedModule"); + static const std::string FakeModuleName("FakeModule"); + + static const std::string FakeContentionFrame("|lm:Unknown-Assembly |ns: |ct:Unknown-Type |cg: |fn:lock-contention |fg: |sg:(?)"); + static const std::string FakeAllocationFrame("|lm:Unknown-Assembly |ns: |ct:Unknown-Type |cg: |fn:allocation |fg: |sg:(?)"); + + + // check for fake IPs used in tests + if (instructionPointer <= MaxFakeIP) + { + // switch/case does not support compile-time constants + if (instructionPointer == FrameStore::FakeLockContentionIP) + { + return { true, {FakeModuleName, FakeContentionFrame, "", 0} }; + } + else + if (instructionPointer == FrameStore::FakeAllocationIP) + { + return { true, {FakeModuleName, FakeAllocationFrame, "", 0} }; + } + else + { + return { true, {FakeModuleName, UnknownManagedFrame, "", 0} }; + } + } std::optional> result = GetFunctionFromIP(instructionPointer); diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.h b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.h index 872f0f8d0a01..a0dff2c7edeb 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.h +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/FrameStore.h @@ -32,15 +32,24 @@ class FrameStore : public IFrameStore std::string Parameters; }; + +// For tests, some IPs are not valid, so we need to fake them +// Since addresses less than 4K are not valid, we use them as fake IPs +public: + static const uintptr_t FakeUnknownIP = 0; + static const uintptr_t FakeLockContentionIP = 1; + static const uintptr_t FakeAllocationIP = 2; + // !! If you add more fake IPs, update this and add new strings in FrameStore.cpp !! + static const uintptr_t MaxFakeIP = 2; + public: FrameStore(ICorProfilerInfo4* pCorProfilerInfo, IConfiguration* pConfiguration, IDebugInfoStore* pDebugInfoStore); -public : +public: std::pair GetFrame(uintptr_t instructionPointer) override; bool GetTypeName(ClassID classId, std::string& name) override; bool GetTypeName(ClassID classId, std::string_view& name) override; - private: std::optional> GetFunctionFromIP(uintptr_t instructionPointer); diff --git a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/IConfiguration.h b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/IConfiguration.h index e7425bbb2df0..d792e31f3716 100644 --- a/profiler/src/ProfilerEngine/Datadog.Profiler.Native/IConfiguration.h +++ b/profiler/src/ProfilerEngine/Datadog.Profiler.Native/IConfiguration.h @@ -69,6 +69,7 @@ class IConfiguration virtual std::uint64_t GetCIVisibilitySpanId() const = 0; virtual bool IsEtwEnabled() const = 0; virtual bool IsEtwLoggingEnabled() const = 0; + virtual std::string const& GetEtwReplayEndpoint() const = 0; virtual EnablementStatus GetEnablementStatus() const = 0; virtual DeploymentMode GetDeploymentMode() const = 0; virtual CpuProfilerType GetCpuProfilerType() const = 0; diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-agent/Program.cs b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-agent/Program.cs new file mode 100644 index 000000000000..10ec82306115 --- /dev/null +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-agent/Program.cs @@ -0,0 +1,91 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; +using System.Threading; + +namespace Datadog.Profiler.IntegrationTests +{ + internal class Program + { + // This application is used to replay events from a .bevents file generated by the dd-prof-etw-client tool + // when a profiled application tries to connect via named pipe (its endpoint is passed as the -e argument). + // 1. start this application with the .bevents file to replay as the -f argument + // 2. start the profiled application using the same named pipe endpoint + // 3. the profiled application sends a register command to the endpoint + // 4. the events will be replayed and sent to the profiled application + // 5. the application stops after the profiled application sends unregister command to the endpoint + // NOTE: the .bevents file must be 32 or 64 compatible with the running profiled application + public static void Main(string[] args) + { + ParseCommandLine(args, out string eventsFilename, out string endpoint); + if (eventsFilename == null) + { + Console.WriteLine("Missing required argument: -f <.bevents file name>"); + return; + } + + Console.WriteLine($"Processing events in {eventsFilename}"); + + if (endpoint == null) + { + Console.WriteLine("Missing required argument: -e "); + return; + } + + ManualResetEventSlim mre = new ManualResetEventSlim(false); + + Console.WriteLine($"Waiting for profiler registration from {endpoint}"); + AgentEtwProxy agentEtwProxy = new AgentEtwProxy(null, endpoint, eventsFilename); + agentEtwProxy.ProfilerRegistered += (sender, e) => + { + Console.WriteLine($"Profiler registered with PID {e.Value}"); + }; + + agentEtwProxy.EventsSent += (sender, e) => + { + Console.WriteLine($"Events sent: {e.Value}"); + }; + + agentEtwProxy.ProfilerUnregistered += (sender, e) => + { + Console.WriteLine($"Profiler unregistered with PID {e.Value}"); + mre.Set(); + }; + + mre.Wait(); + } + + private static void ParseCommandLine(string[] args, out string eventsFilename, out string endpoint) + { + eventsFilename = null; + endpoint = null; + + for (int i = 0; i < args.Length; i++) + { + string arg = args[i]; + if ("-f".Equals(arg, StringComparison.OrdinalIgnoreCase)) + { + // a filename is expected + i++; + if (i < args.Length) + { + eventsFilename = args[i]; + } + } + else + if ("-e".Equals(arg, StringComparison.OrdinalIgnoreCase)) + { + // a namedpipe endpoint is expected such as "\\\\.\\pipe\\DD_ETW_TEST_AGENT" + i++; + if (i < args.Length) + { + endpoint = args[i]; + } + } + } + } + } +} diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-agent/dd-prof-etw-agent.csproj b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-agent/dd-prof-etw-agent.csproj new file mode 100644 index 000000000000..2f9e6ad54ae1 --- /dev/null +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-agent/dd-prof-etw-agent.csproj @@ -0,0 +1,21 @@ + + + + Exe + net8.0 + Datadog.Profiler.IntegrationTests + + + + + + + + + + + + + + + diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/EtwEventDumper.cpp b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/EtwEventDumper.cpp index 227ea11d0ac9..30679c163aa5 100644 --- a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/EtwEventDumper.cpp +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/EtwEventDumper.cpp @@ -10,7 +10,6 @@ #include #include - bool EtwEventDumper::BuildClrEvent( std::string& name, uint32_t tid, uint8_t version, uint16_t id, uint64_t keyword, uint8_t level, @@ -183,7 +182,7 @@ void EtwEventDumper::DumpAllocationTick(uint32_t cbEventData, const uint8_t* pEv { std::wcout << L" large | "; } - std::wcout << (wchar_t*)&(pPayload->TypeName) << L"\n"; + std::wcout << (wchar_t*)&(pPayload->FirstCharInName) << L"\n"; } void EtwEventDumper::OnEvent( diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.cpp b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.cpp index 57c163f8d18a..ff85390c76fa 100644 --- a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.cpp +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.cpp @@ -3,12 +3,13 @@ // Inspired by https://github.com/zodiacon/Win10SysProgBookSamples/blob/master/Chapter18/CalculatorSvr/CalculatorSvr.cpp // Another implementation without using ThreadPool API - https://learn.microsoft.com/en-us/windows/win32/ipc/multithreaded-pipe-server -#include #include #include #include +#include "stdio.h" #include +#include #include "..\..\..\..\ProfilerEngine\Datadog.Profiler.Native.Windows\ETW\Protocol.h" #include "..\..\..\..\ProfilerEngine\Datadog.Profiler.Native.Windows\ETW\IpcClient.h" @@ -17,17 +18,22 @@ #include "EtwEventDumper.h" #include "..\ConsoleLogger.h" + +// This application should be used in conjunction with a profiled .NET application that is emitting ETW events +// for a certain scenario and serializes them into a .bevents file that can be replayed by dd-prof-etw-replay but +// also during integration tests via the AgentEtwProxy integrated in the MockDatadogAgent. +// NOTE: no 32/64 bit difference because the events are serialized as received void ShowHelp() { printf("\nDatadog CLR Events Client v1.1\n"); printf("Simulate a .NET profiled application asking for ETW CLR events via named pipes.\n"); printf("\n"); - printf("Usage: -pid \n"); - printf(" Ex: -pid 1234\n"); + printf("Usage: -pid -r \n"); + printf(" Ex: -pid 1234 -r gc.bevents\n"); printf("\n"); } -bool ParseCommandLine(int argc, char* argv[], int& pid, bool& needHelp) +bool ParseCommandLine(int argc, char* argv[], int& pid, std::string& eventsFilename, bool& needHelp) { bool success = false; @@ -52,6 +58,16 @@ bool ParseCommandLine(int argc, char* argv[], int& pid, bool& needHelp) success = (pid != 0); } else + if (strcmp(argv[i], "-r") == 0) + { + if (i == argc - 1) + { + return false; + } + + eventsFilename = argv[i+1]; + } + else if (strcmp(argv[i], "-help") == 0) { needHelp = true; @@ -154,7 +170,8 @@ int main(int argc, char* argv[]) int pid = -1; const char* pipe = "DD_ETW_DISPATCHER"; bool needHelp = false; - if (!ParseCommandLine(argc, argv, pid, needHelp)) + std::string eventsFilename; + if (!ParseCommandLine(argc, argv, pid, eventsFilename, needHelp)) { if (pid == -1) { @@ -170,6 +187,18 @@ int main(int argc, char* argv[]) return 0; } + FILE* pEventsFile = nullptr; + if (!eventsFilename.empty()) + { + pEventsFile = fopen(eventsFilename.c_str(), "wb"); + if (pEventsFile == nullptr) + { + std::cout << "Impossible to create the events file " << eventsFilename << "...\n"; + return -1; + } + std::cout << "Events will be saved into the file " << eventsFilename << "\n"; + } + std::cout << "\n"; // start the server part to receive proxied ETW events @@ -181,7 +210,7 @@ int main(int argc, char* argv[]) EtwEventDumper eventDumper; std::unique_ptr logger = std::make_unique(); - auto handler = std::make_unique(logger.get(), &eventDumper); + auto handler = std::make_unique(logger.get(), &eventDumper, pEventsFile); auto server = IpcServer::StartAsync( logger.get(), pipeName, @@ -218,7 +247,7 @@ int main(int argc, char* argv[]) SendRegistrationCommand(client.get(), pid, false); client->Disconnect(); - handler->Stop(); + handler->Cleanup(); server->Stop(); return 0; diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.vcxproj b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.vcxproj index 64c497c283f2..f9ba5ee5a7f5 100644 --- a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.vcxproj +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-client/dd-prof-etw-client.vcxproj @@ -74,7 +74,7 @@ Level3 true - WIN32;_DEBUG;_CONSOLE;%(PreprocessorDefinitions) + _CRT_SECURE_NO_WARNINGS;WIN32;_DEBUG;_CONSOLE;%(PreprocessorDefinitions) true @@ -102,7 +102,7 @@ Level3 true - _DEBUG;_CONSOLE;%(PreprocessorDefinitions) + _CRT_SECURE_NO_WARNINGS;_DEBUG;_CONSOLE;%(PreprocessorDefinitions) true @@ -116,7 +116,7 @@ true true true - NDEBUG;_CONSOLE;%(PreprocessorDefinitions) + _CRT_SECURE_NO_WARNINGS;NDEBUG;_CONSOLE;%(PreprocessorDefinitions) true diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/EventDumper.cs b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/EventDumper.cs new file mode 100644 index 000000000000..e07ca4d49f36 --- /dev/null +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/EventDumper.cs @@ -0,0 +1,124 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; +using System.Runtime.InteropServices; + +namespace Datadog.Profiler.IntegrationTests +{ + public class EventDumper : IEventDumper + { + // keywords + private const ulong KeywordContention = 0x00004000; + private const ulong KeywordStack = 0x40000000; + private const ulong KeywordGC = 0x00000001; + + // events +#pragma warning disable SA1310 // Field names should not contain underscore + private const int EVENT_CONTENTION_STOP = 91; // version 1 contains the duration in nanoseconds + private const int EVENT_CONTENTION_START = 81; + + private const int EVENT_SW_STACK = 82; + + private const int EVENT_ALLOCATION_TICK = 10; // version 4 contains the size + reference + private const int EVENT_GC_TRIGGERED = 35; + private const int EVENT_GC_START = 1; // V2 + private const int EVENT_GC_END = 2; // V1 + private const int EVENT_GC_HEAP_STAT = 4; // V1 + private const int EVENT_GC_PER_HEAP_HISTORY = 204; + private const int EVENT_GC_GLOBAL_HEAP_HISTORY = 205; // V2 + private const int EVENT_GC_SUSPEND_EE_BEGIN = 9; // V1 + private const int EVENT_GC_RESTART_EE_END = 3; // V2 +#pragma warning restore SA1310 // Field names should not contain underscore + + private int _lastGC = 0; + + public void DumpEvent(ulong timestamp, uint tid, uint version, ulong keyword, byte level, uint id, Span eventData) + { + //Console.WriteLine($"{timestamp,12} | {tid,6} - [{keyword,8:x}, {level,2}] = ({id,3}, {version,2}) with {eventData.Length} bytes"); + var description = GetEventName(keyword, id, eventData); + if (description != id.ToString()) + { + Console.WriteLine($" {description}"); + } + } + + private string GetEventName(ulong keyword, uint id, Span eventData) + { + switch (keyword) + { + case KeywordGC: + return GetGCEventName(id, eventData); + + case KeywordContention: + return GetContentionEvenName(id, eventData); + + case KeywordStack: + if (id == EVENT_SW_STACK) + { + return "Stack"; + } + else + { + return id.ToString(); + } + + default: + return id.ToString(); + } + } + + private string GetGCEventName(uint id, Span eventData) + { + switch (id) + { + case EVENT_GC_TRIGGERED: + { + return $"GC Triggered"; + } + + case EVENT_GC_START: + { + MemoryMarshal.TryRead(eventData, out int count); + MemoryMarshal.TryRead(eventData.Slice(4), out int generation); + return $"GC Start #{count} gen {generation}"; + } + + case EVENT_GC_END: + { + MemoryMarshal.TryRead(eventData, out int count); + MemoryMarshal.TryRead(eventData.Slice(4), out int generation); + return $"GC End #{count} gen {generation}"; + } + + case EVENT_GC_HEAP_STAT: + return "GC Heap Stat"; + case EVENT_GC_PER_HEAP_HISTORY: + return "GC Per Heap History"; + case EVENT_GC_GLOBAL_HEAP_HISTORY: + return "GC Global Heap History"; + case EVENT_GC_SUSPEND_EE_BEGIN: + return "GC Suspend EE Begin"; + case EVENT_GC_RESTART_EE_END: + return "GC Restart EE End"; + default: + return id.ToString(); + } + } + + private string GetContentionEvenName(uint id, Span eventData) + { + switch (id) + { + case EVENT_CONTENTION_START: + return "Contention Start"; + case EVENT_CONTENTION_STOP: + return "Contention Stop"; + default: + return id.ToString(); + } + } + } +} diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/Program.cs b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/Program.cs new file mode 100644 index 000000000000..5071542d18dc --- /dev/null +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/Program.cs @@ -0,0 +1,72 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; +using System.IO; + +namespace Datadog.Profiler.IntegrationTests +{ + internal class Program + { + // This application reads a .bevents file and dumps the records and events + // It is used to validate the .bevents file generated by the dd-prof-etw-client tool + private static void Main(string[] args) + { + try + { + ParseCommandLine(args, out string eventsFilename); + if (eventsFilename == null) + { + throw new ArgumentException("Missing required argument: -f <.bevents file name>"); + } + + Console.WriteLine($"Processing events in {eventsFilename}"); + + using (FileStream fs = new FileStream(eventsFilename, FileMode.Open, FileAccess.Read)) + using (BinaryReader reader = new BinaryReader(fs)) + { + var recordDumper = new RecordDumper(); + var eventDumper = new EventDumper(); + var recordReader = new RecordReader(reader, recordDumper, eventDumper); + int count = 0; + while (fs.Position < fs.Length) + { + var current = ++count; + //Console.Write($"#{current,6} "); + recordReader.ReadRecord(); + } + + Console.WriteLine($"Total = {count} records"); + } + } + catch (Exception x) + { + Console.WriteLine("Replay recorded ETW events"); + Console.WriteLine(" -f <.bevents file name>"); + Console.WriteLine("----------------------------------------------------"); + Console.WriteLine($"Error: {x.Message}"); + } + } + + private static void ParseCommandLine(string[] args, out string eventsFilename) + { + eventsFilename = null; + + for (int i = 0; i < args.Length; i++) + { + string arg = args[i]; + if ("-f".Equals(arg, StringComparison.OrdinalIgnoreCase)) + { + // a filename is expected + i++; + if (i < args.Length) + { + eventsFilename = args[i]; + } + } + } + } + } +} diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/RecordDumper.cs b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/RecordDumper.cs new file mode 100644 index 000000000000..2dd242e805bf --- /dev/null +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/RecordDumper.cs @@ -0,0 +1,17 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; + +namespace Datadog.Profiler.IntegrationTests +{ + public class RecordDumper : IRecordDumper + { + public void DumpRecord(byte[] record, int recordSize) + { + //Console.WriteLine($"> record size = {recordSize}"); + } + } +} diff --git a/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/dd-prof-etw-replay.csproj b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/dd-prof-etw-replay.csproj new file mode 100644 index 000000000000..7b384b89b186 --- /dev/null +++ b/profiler/src/Tools/ETW/dd-prof-etw/dd-prof-etw-replay/dd-prof-etw-replay.csproj @@ -0,0 +1,12 @@ + + + Exe + net8.0 + Datadog.Profiler.IntegrationTests + + + + + + + diff --git a/profiler/src/Tools/ETW/dd-prof-etw/read.me b/profiler/src/Tools/ETW/dd-prof-etw/read.me new file mode 100644 index 000000000000..40601e33243b --- /dev/null +++ b/profiler/src/Tools/ETW/dd-prof-etw/read.me @@ -0,0 +1,50 @@ +These tools are used in different scenario related to the support of ETW events for .NET Framework applications" +- dd-prof-etw-collector: application used to simulate the named pipe endpoint of the Datadog Agent the profiler connect to receive ETW events (support register/unregister commands) +- dd-prof-etw-client: application used to implement and debug C++ classes used by the profiler to connect to the Agent and receive ETW events. It was used by the Agent to easily test the protocol (i.e. replacing a profiled application). It requires another .NET application that implements scenarios corresponding to interesting events. These events can also be recorded in .bevents files that are used in integration tests to replay the scenarios without the Agent. +- dd-prof-etw-agent: application used to implement and debug C# AgentEtwProxy class used to emulate the named pipe protocol for integration tests +- dd-prof-etw-replay: application used to implement and debug C# classes used to deserialize events stored in .bevents files + + +How to add an integration test for .NET Framework +---------------------------------------------------------------------- +NOTE: scenario application must be run in both 32 bit and 64 bit +1. write the C# code corresponding to the scenario (i.e. generating GCs, lock contention or allocations) +2. run in x64 the corresponding app that displays its PID and wait for user input before starting the scenario that will generate events +3. run dd-prof-etw-client with -pid -r +4. trigger the scenario in the C# application +5. copy the generated .bevents file to the integration test folder +6. change its properties in the integration test project: Build Action = Content and Copy to Output Directory = always +7. do the same steps 2 to 6 but in x86 +8. add the following code in the integration test byt changing the filenames + using var agent = MockDatadogAgent.CreateHttpAgent(_output); + if (IntPtr.Size == 4) + { + // 32-bit + agent.StartEtwProxy("DD_ETW_TEST_AGENT", "Contention\\lockContention-32.bevents"); + } + else + { + // 64-bit + agent.StartEtwProxy("DD_ETW_TEST_AGENT", "Contention\\lockContention-64.bevents"); + } + int eventsCount = 0; + agent.EventsSent += (sender, e) => eventsCount = e.Value; + runner.Run(agent); + +9. ensure that events are received + Assert.True(eventsCount > 0); + +10. look at the generated .pprof for expected samples + + +How to debug an integration test .bevents file scenario +---------------------------------------------------------------------- +If it is needed to debug the profiler event parsing code based on a .bevents scenario file, follow these steps: +1. run dd-prof-etw-agent with -f -e DD_ETW_TEST_AGENT +2. debug Samples.Computer01 project with the needed env var set including + "DD_INTERNAL_PROFILING_ETW_ENABLED": "1", + "DD_INTERNAL_ETW_LOGGING_ENABLED": "1", + "DD_INTERNAL_ETW_ENDPOINT": "\\\\.\\pipe\\DD_ETW_TEST_AGENT", +3. set breakpoints in EtwEventsManager.cpp in OnEvent() and ClrEventsParser.cpp if needed + +NOTE: if the protocol itself seems broken, it is also possible to debug dd-prof-etw-agent in step 1 and set breakpoints in AgentEtwProxy.cs diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/AllocationsProfilerTest.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/AllocationsProfilerTest.cs index 1740c292783d..48ded5046633 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/AllocationsProfilerTest.cs +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/AllocationsProfilerTest.cs @@ -18,6 +18,7 @@ public class AllocationsProfilerTest { private const string ScenarioGenerics = "--scenario 9"; private const string ScenarioMeasureAllocation = "--scenario 16"; + private const string ScenarioWithoutGC = "--scenario 25 --threads 2 --param 1000"; private readonly ITestOutputHelper _output; @@ -45,7 +46,7 @@ public void ShouldAllocationProfilerBeDisabledByDefault(string appName, string f var runner = new TestApplicationRunner(appName, framework, appAssembly, _output, commandLine: ScenarioGenerics); EnvironmentHelper.DisableDefaultProfilers(runner); - using var agent = MockDatadogAgent.CreateHttpAgent(_output); + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); runner.Run(agent); @@ -69,7 +70,7 @@ public void ExplicitlyDisableAllocationProfiler(string appName, string framework runner.Environment.SetVariable(EnvironmentVariables.WallTimeProfilerEnabled, "1"); runner.Environment.SetVariable(EnvironmentVariables.AllocationProfilerEnabled, "0"); - using var agent = MockDatadogAgent.CreateHttpAgent(_output); + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); runner.Run(agent); @@ -85,7 +86,7 @@ public void MeasureAllocations(string appName, string framework, string appAssem EnvironmentHelper.DisableDefaultProfilers(runner); runner.Environment.SetVariable(EnvironmentVariables.AllocationProfilerEnabled, "1"); - using var agent = MockDatadogAgent.CreateHttpAgent(_output); + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); runner.Run(agent); @@ -98,10 +99,10 @@ public void MeasureAllocations(string appName, string framework, string appAssem Dictionary profiledAllocations = GetProfiledAllocations(allocationSamples); Dictionary realAllocations = GetRealAllocations(runner.ProcessOutput); - _output.WriteLine("Comparing allocations"); - _output.WriteLine("-------------------------------------------------------"); - _output.WriteLine(" Count Size Type"); - _output.WriteLine("-------------------------------------------------------"); + runner.XUnitLogger.WriteLine("Comparing allocations"); + runner.XUnitLogger.WriteLine("-------------------------------------------------------"); + runner.XUnitLogger.WriteLine(" Count Size Type"); + runner.XUnitLogger.WriteLine("-------------------------------------------------------"); foreach (var allocation in profiledAllocations) { var allocStats = allocation.Value; @@ -121,10 +122,43 @@ public void MeasureAllocations(string appName, string framework, string appAssem StringBuilder builder = new StringBuilder(); builder.AppendLine($"{allocStats.Count,11} {allocStats.Size,13} {type}"); builder.AppendLine($"{stats.Count,11} {stats.Size,13}"); - _output.WriteLine(builder.ToString()); + runner.XUnitLogger.WriteLine(builder.ToString()); } } + [TestAppFact("Samples.Computer01", new[] { "net462" })] + public void ShouldGetAllocationSamplesViaEtw(string appName, string framework, string appAssembly) + { + var runner = new TestApplicationRunner(appName, framework, appAssembly, _output, commandLine: ScenarioWithoutGC); + + EnvironmentHelper.DisableDefaultProfilers(runner); + runner.Environment.SetVariable(EnvironmentVariables.AllocationProfilerEnabled, "1"); + runner.Environment.SetVariable(EnvironmentVariables.EtwEnabled, "1"); + Guid guid = Guid.NewGuid(); + runner.Environment.SetVariable(EnvironmentVariables.EtwReplayEndpoint, "\\\\.\\pipe\\DD_ETW_TEST_AGENT-" + guid); + + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); + if (IntPtr.Size == 4) + { + // 32-bit + agent.StartEtwProxy(runner.XUnitLogger, "DD_ETW_TEST_AGENT-" + guid, "Allocations\\allocations-32.bevents"); + } + else + { + // 64-bit + agent.StartEtwProxy(runner.XUnitLogger, "DD_ETW_TEST_AGENT-" + guid, "Allocations\\allocations-64.bevents"); + } + + int eventsCount = 0; + agent.EventsSent += (sender, e) => eventsCount = e.Value; + runner.Run(agent); + + Assert.True(agent.NbCallsOnProfilingEndpoint > 0); + + var allocationSamples = ExtractAllocationSamples(runner.Environment.PprofDir).ToArray(); + allocationSamples.Should().NotBeEmpty(); + } + private static Dictionary GetProfiledAllocations(IEnumerable<(string Type, long Count, long Size, StackTrace Stacktrace)> allocations) { var profiledAllocations = new Dictionary(); @@ -313,7 +347,12 @@ private static int GotoEoL(string text, int pos) continue; } - var size = sample.Value[1]; + long size = 0; + // no size available for .NET Framework + if (sample.Value.Count > 1) + { + size = sample.Value[1]; + } var labels = sample.Labels(profile).ToArray(); @@ -332,7 +371,7 @@ private static int GotoEoL(string text, int pos) private void CheckAllocationProfiles(TestApplicationRunner runner) { - using var agent = MockDatadogAgent.CreateHttpAgent(_output); + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); runner.Run(agent); diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/allocations-32.bevents b/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/allocations-32.bevents new file mode 100644 index 000000000000..c20f2fdfe6e5 Binary files /dev/null and b/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/allocations-32.bevents differ diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/allocations-64.bevents b/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/allocations-64.bevents new file mode 100644 index 000000000000..db78b48fe15b Binary files /dev/null and b/profiler/test/Datadog.Profiler.IntegrationTests/Allocations/allocations-64.bevents differ diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Contention/ContentionProfilerTest.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Contention/ContentionProfilerTest.cs index df2996dacde1..760ed69d94fe 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/Contention/ContentionProfilerTest.cs +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Contention/ContentionProfilerTest.cs @@ -15,6 +15,7 @@ namespace Datadog.Profiler.IntegrationTests.Contention public class ContentionProfilerTest { private const string ScenarioContention = "--scenario 10 --threads 20"; + private const string ScenarioWithoutContention = "--scenario 25 --threads 2 --param 1000"; private readonly ITestOutputHelper _output; @@ -85,6 +86,45 @@ public void ExplicitlyDisableContentionProfiler(string appName, string framework SamplesHelper.CheckSamplesValueCount(runner.Environment.PprofDir, 1); } + [TestAppFact("Samples.Computer01", new[] { "net462" })] + public void ShouldGetLockContentionSamplesViaEtw(string appName, string framework, string appAssembly) + { + var runner = new TestApplicationRunner(appName, framework, appAssembly, _output, commandLine: ScenarioWithoutContention); + + EnvironmentHelper.DisableDefaultProfilers(runner); + runner.Environment.SetVariable(EnvironmentVariables.ContentionProfilerEnabled, "1"); + runner.Environment.SetVariable(EnvironmentVariables.EtwEnabled, "1"); + Guid guid = Guid.NewGuid(); + runner.Environment.SetVariable(EnvironmentVariables.EtwReplayEndpoint, "\\\\.\\pipe\\DD_ETW_TEST_AGENT-" + guid); + + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); + if (IntPtr.Size == 4) + { + // 32-bit + agent.StartEtwProxy(runner.XUnitLogger, "DD_ETW_TEST_AGENT-" + guid, "Contention\\lockContention-32.bevents"); + } + else + { + // 64-bit + agent.StartEtwProxy(runner.XUnitLogger, "DD_ETW_TEST_AGENT-" + guid, "Contention\\lockContention-64.bevents"); + } + + int eventsCount = 0; + agent.EventsSent += (sender, e) => eventsCount = e.Value; + + runner.Run(agent); + + Assert.True(agent.NbCallsOnProfilingEndpoint > 0); + AssertContainLockContentionSamples(runner.Environment.PprofDir); + Assert.True(eventsCount > 0); + } + + private static void AssertContainLockContentionSamples(string pprofDir) + { + var contentionSamples = SamplesHelper.GetSamples(pprofDir, "lock-count"); + contentionSamples.Should().NotBeEmpty(); + } + private static void AssertBlockingThreadLabel(string pprofDir) { var threadIds = SamplesHelper.GetThreadIds(pprofDir); diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Contention/lockContention-32.bevents b/profiler/test/Datadog.Profiler.IntegrationTests/Contention/lockContention-32.bevents new file mode 100644 index 000000000000..43db0c48e7bb Binary files /dev/null and b/profiler/test/Datadog.Profiler.IntegrationTests/Contention/lockContention-32.bevents differ diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Contention/lockContention-64.bevents b/profiler/test/Datadog.Profiler.IntegrationTests/Contention/lockContention-64.bevents new file mode 100644 index 000000000000..e17e8037be93 Binary files /dev/null and b/profiler/test/Datadog.Profiler.IntegrationTests/Contention/lockContention-64.bevents differ diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Datadog.Profiler.IntegrationTests.csproj b/profiler/test/Datadog.Profiler.IntegrationTests/Datadog.Profiler.IntegrationTests.csproj index 4f20104113b9..3699cb8c4365 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/Datadog.Profiler.IntegrationTests.csproj +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Datadog.Profiler.IntegrationTests.csproj @@ -1,7 +1,7 @@  - net7.0 + net8.0 false latest AnyCPU;x64;x86 @@ -20,7 +20,31 @@ + + + + + + + + Always + + + Always + + + Always + + + Always + + + Always + + + Always + diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/3x3GCs-32.bevents b/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/3x3GCs-32.bevents new file mode 100644 index 000000000000..532831e0dc43 Binary files /dev/null and b/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/3x3GCs-32.bevents differ diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/3x3GCs-64.bevents b/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/3x3GCs-64.bevents new file mode 100644 index 000000000000..19ba3fe9ea91 Binary files /dev/null and b/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/3x3GCs-64.bevents differ diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/GarbageCollectionsProfilerTest.cs b/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/GarbageCollectionsProfilerTest.cs index c11efce42dc2..4e3cd453ece2 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/GarbageCollectionsProfilerTest.cs +++ b/profiler/test/Datadog.Profiler.IntegrationTests/GarbageCollections/GarbageCollectionsProfilerTest.cs @@ -3,6 +3,7 @@ // This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. // +using System; using System.Linq; using Datadog.Profiler.IntegrationTests.Helpers; using Xunit; @@ -13,6 +14,7 @@ namespace Datadog.Profiler.IntegrationTests.GarbageCollections public class GarbageCollectionsProfilerTest { private const string ScenarioGenerics = "--scenario 12"; + private const string ScenarioWithoutGC = "--scenario 25 --threads 2 --param 1000"; private const string GcRootFrame = "|lm: |ns: |ct: |cg: |fn:Garbage Collector |fg: |sg:"; private readonly ITestOutputHelper _output; @@ -32,7 +34,7 @@ public void ShouldGetGarbageCollectionSamples(string appName, string framework, runner.Environment.SetVariable(EnvironmentVariables.GarbageCollectionProfilerEnabled, "1"); // only garbage collection profiler enabled so should only see the 1 related value per sample + Generation label - using var agent = MockDatadogAgent.CreateHttpAgent(_output); + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); runner.Run(agent); Assert.True(agent.NbCallsOnProfilingEndpoint > 0); Assert.True(CheckSamplesAreGC(runner.Environment.PprofDir)); @@ -50,12 +52,48 @@ public void ShouldGetGarbageCollectionSamplesByDefault(string appName, string fr runner.Environment.SetVariable(EnvironmentVariables.ContentionProfilerEnabled, "0"); // only garbage collection profiler enabled so should only see the 1 related value per sample + Generation label - using var agent = MockDatadogAgent.CreateHttpAgent(_output); + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); runner.Run(agent); Assert.True(agent.NbCallsOnProfilingEndpoint > 0); Assert.True(CheckSamplesAreGC(runner.Environment.PprofDir)); } + [TestAppFact("Samples.Computer01", new[] { "net462" })] + public void ShouldGetGarbageCollectionSamplesViaEtw(string appName, string framework, string appAssembly) + { + var runner = new TestApplicationRunner(appName, framework, appAssembly, _output, commandLine: ScenarioWithoutGC); + + // disable default profilers except GC + runner.Environment.SetVariable(EnvironmentVariables.WallTimeProfilerEnabled, "0"); + runner.Environment.SetVariable(EnvironmentVariables.CpuProfilerEnabled, "0"); + runner.Environment.SetVariable(EnvironmentVariables.ExceptionProfilerEnabled, "0"); + runner.Environment.SetVariable(EnvironmentVariables.ContentionProfilerEnabled, "0"); + runner.Environment.SetVariable(EnvironmentVariables.EtwEnabled, "1"); + Guid guid = Guid.NewGuid(); + runner.Environment.SetVariable(EnvironmentVariables.EtwReplayEndpoint, "\\\\.\\pipe\\DD_ETW_TEST_AGENT-" + guid); + + using var agent = MockDatadogAgent.CreateHttpAgent(runner.XUnitLogger); + if (IntPtr.Size == 4) + { + // 32-bit + agent.StartEtwProxy(runner.XUnitLogger, "DD_ETW_TEST_AGENT-" + guid, "GarbageCollections\\3x3GCs-32.bevents"); + } + else + { + // 64-bit + agent.StartEtwProxy(runner.XUnitLogger, "DD_ETW_TEST_AGENT-" + guid, "GarbageCollections\\3x3GCs-64.bevents"); + } + + int eventsCount = 0; + agent.EventsSent += (sender, e) => eventsCount = e.Value; + runner.Run(agent); + + Assert.True(agent.NbCallsOnProfilingEndpoint > 0); + Assert.True(eventsCount > 0); + Assert.True(CheckSamplesAreGC(runner.Environment.PprofDir)); + // TODO: it should be possible to ensure that 3 GCs per generations are seen in the .pprof files + } + private bool CheckSamplesAreGC(string directory) { var rootFrame = new StackFrame(GcRootFrame); diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/AgentEtwProxy.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/AgentEtwProxy.cs new file mode 100644 index 000000000000..52cf57d2478e --- /dev/null +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/AgentEtwProxy.cs @@ -0,0 +1,233 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; +using System.IO; +using System.IO.Pipes; +using System.Runtime.InteropServices; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using Xunit.Abstractions; + +namespace Datadog.Profiler.IntegrationTests +{ + public class AgentEtwProxy : IRecordDumper + { + // endpoint serviced by the profiler based on its PID + private const string ProfilerNamedPipePrefix = "DD_ETW_CLIENT_"; + + private readonly ITestOutputHelper _output; + private string _agentEndPoint; + private string _eventsFilename; + private bool _profilerHasRegistered; + private bool _profilerHasUnregistered; + private bool _eventsHaveBeenSent; + private int _pid; + private NamedPipeClientStream _pipeClient; + + public AgentEtwProxy(ITestOutputHelper output, string agentEndPoint, string eventsFilename) + { + _agentEndPoint = agentEndPoint; + _eventsFilename = eventsFilename; + _profilerHasRegistered = false; + _profilerHasUnregistered = false; + _eventsHaveBeenSent = false; + _pipeClient = null; + _output = output; + } + + // ---------------------------------PID + public event EventHandler> ProfilerRegistered; + + // ---------------------------------number of events sent + public event EventHandler> EventsSent; + + // ---------------------------------PID + public event EventHandler> ProfilerUnregistered; + + public bool ProfilerHasRegistered { get => _profilerHasRegistered; } + + public bool ProfilerHasUnregistered { get => _profilerHasUnregistered; } + + public bool EventsHaveBeenSent { get => _eventsHaveBeenSent; } + + public void DumpRecord(byte[] record, int recordSize) + { + if (_pipeClient == null) + { + throw new ArgumentNullException("_pipeClient"); + } + + // Send the byte[] buffer to the server + _pipeClient.Write(record, 0, recordSize); + _pipeClient.Flush(); + + // NOTE: this is a fire and forget call: no answer is expected from the profiler + } + + public async Task StartServerAsync() + { + Thread.CurrentThread.Name = "AgentProxy"; + try + { + // simulate the Agent that accepts register/unregister commands from the profiler +#pragma warning disable CA1416 // Validate platform compatibility + using (var server = new NamedPipeServerStream( + _agentEndPoint, + PipeDirection.InOut, + 2, + PipeTransmissionMode.Message, + PipeOptions.WriteThrough)) + { + WriteLine($"NamedPipeServer is waiting for a connection on {_agentEndPoint}..."); + + await server.WaitForConnectionAsync(); + + WriteLine("Client connected."); + byte[] inBuffer = new byte[256]; + int bytesRead; + byte[] outBuffer = new byte[256]; + + while ((bytesRead = await server.ReadAsync(inBuffer, 0, inBuffer.Length)) > 0) + { + bool success = ProcessCommand(inBuffer); + + // build the response based on success/failure + IpcHeader header = new IpcHeader + { + Size = IpcHeader.HeaderSize, + CommandIdOrResponseCode = success ? ResponseCodes.Success : ResponseCodes.Failure, + }; + Encoding.ASCII.GetBytes( + IpcHeader.MagicValue, + MemoryMarshal.CreateSpan(ref header.Magic._element, 14)); + MemoryMarshal.Write(outBuffer, in header); + + server.Write(outBuffer, 0, IpcHeader.HeaderSize); + server.Flush(); + server.WaitForPipeDrain(); + } + } +#pragma warning restore CA1416 // Validate platform compatibility + } + catch (Exception ex) + { + WriteLine($"StartServerAsync: {ex.Message}"); + } + } + + private void OnProfilerRegistered(int pid) + { + WriteLine($"process {pid} has registered"); + ProfilerRegistered?.Invoke(this, new EventArgs(pid)); + } + + private void OnEventsSent(int count) + { + EventsSent?.Invoke(this, new EventArgs(count)); + } + + private void OnProfilerUnregistered(int pid) + { + WriteLine($"process {pid} is unregistered"); + ProfilerUnregistered?.Invoke(this, new EventArgs(pid)); + } + + private void WriteLine(string line) + { + if (_output != null) + { + _output.WriteLine(line); + } + else + { + Console.WriteLine(line); + } + } + + private bool ProcessCommand(byte[] receivedData) + { + RegistrationCommand command = MemoryMarshal.Read(receivedData); + + // TODO: check header with magic number + + // handle register and unregister commands + if (command.Header.CommandIdOrResponseCode == AgentCommands.Register) + { + _pid = (int)command.Pid; + OnProfilerRegistered(_pid); + _profilerHasRegistered = (_pid != 0); + + if (_profilerHasRegistered) + { + // NOTE: we want to accept the profiler registration command before starting to send events from another thread + // so we don't await this async method + Task.Run(StartClientAsync); + } + + return _profilerHasRegistered; + } + else if (command.Header.CommandIdOrResponseCode == AgentCommands.Unregister) + { + OnProfilerUnregistered((int)command.Pid); + _profilerHasUnregistered = (_pid != (int)command.Pid); + + return _profilerHasUnregistered; + } + + return (command.Header.CommandIdOrResponseCode == AgentCommands.KeepAlive); + } + + private async Task StartClientAsync() + { + // let the profiler initialize before sending events + Thread.Sleep(500); + + string endPoint = ProfilerNamedPipePrefix + _pid.ToString(); + WriteLine($"Connecting to the profiler on {endPoint}..."); + using (NamedPipeClientStream pipeClient = new NamedPipeClientStream(".", endPoint, PipeDirection.Out)) + { + _pipeClient = pipeClient; + + try + { + // Connect to the NamedPipe server + await pipeClient.ConnectAsync(); + WriteLine("Connected to the Profiler"); + + // read the events file and send each event to the profiler + if (_eventsFilename != null) + { + using (FileStream fs = new FileStream(_eventsFilename, FileMode.Open, FileAccess.Read)) + using (BinaryReader reader = new BinaryReader(fs)) + { + var recordReader = new RecordReader(reader, this, null); + int count = 0; + + WriteLine("Start replaying events..."); + + // each records will be processed by the DumpRecord method + while (fs.Position < fs.Length) + { + count++; + WriteLine($"Sending event {count}..."); + recordReader.ReadRecord(); + } + + WriteLine($"{count} events have been replayed"); + _eventsHaveBeenSent = true; + OnEventsSent(count); + } + } + } + catch (Exception ex) + { + WriteLine($"StartClientAsync: {ex.Message}"); + } + } + } + } +} diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/EnvironmentVariables.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/EnvironmentVariables.cs index 6201b69f2d27..5dd89adbe62b 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/EnvironmentVariables.cs +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/EnvironmentVariables.cs @@ -32,6 +32,7 @@ internal class EnvironmentVariables public const string CpuProfilingInterval = "DD_INTERNAL_CPU_PROFILING_INTERVAL"; public const string SsiShortLivedThreshold = "DD_INTERNAL_PROFILING_LONG_LIVED_THRESHOLD"; public const string TelemetryToDiskEnabled = "DD_INTERNAL_PROFILING_TELEMETRY_TO_DISK_ENABLED"; + public const string EtwReplayEndpoint = "DD_INTERNAL_ETW_REPLAY_ENDPOINT"; public const string SsiTelemetryEnabled = "DD_INTERNAL_PROFILING_SSI_TELEMETRY_ENABLED"; } } diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/IEventDumper.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/IEventDumper.cs new file mode 100644 index 000000000000..a703d580b5f2 --- /dev/null +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/IEventDumper.cs @@ -0,0 +1,21 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; + +namespace Datadog.Profiler.IntegrationTests +{ + public interface IEventDumper + { + public abstract void DumpEvent( + UInt64 timestamp, + UInt32 tid, + UInt32 version, + UInt64 keyword, + byte level, + UInt32 id, + Span eventData); + } +} diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/IRecordDumper.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/IRecordDumper.cs new file mode 100644 index 000000000000..985e5afdd9ca --- /dev/null +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/IRecordDumper.cs @@ -0,0 +1,12 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +namespace Datadog.Profiler.IntegrationTests +{ + public interface IRecordDumper + { + public abstract void DumpRecord(byte[] record, int recordSize); + } +} diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/MemoryDumpHelper.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/MemoryDumpHelper.cs new file mode 100644 index 000000000000..e653596118cf --- /dev/null +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/MemoryDumpHelper.cs @@ -0,0 +1,95 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; +using System.Diagnostics; +using System.IO; +using System.Net.Http; +using System.Threading.Tasks; +using Xunit.Abstractions; + +namespace Datadog.Profiler.IntegrationTests.Helpers +{ + // This is a Windows only implementation + public class MemoryDumpHelper + { + private static string _path; + + public static bool IsAvailable => _path != null; + + public static async Task InitializeAsync(ITestOutputHelper output) + { + // We don't know if procdump is available, so download it fresh + const string url = "https://download.sysinternals.com/files/Procdump.zip"; + var client = new HttpClient(); + var zipFilePath = Path.GetTempFileName(); + output.WriteLine($"Downloading Procdump to '{zipFilePath}'"); + using (var response = await client.GetAsync(url, HttpCompletionOption.ResponseHeadersRead)) + { + using var bodyStream = await response.Content.ReadAsStreamAsync(); + using Stream streamToWriteTo = File.Open(zipFilePath, FileMode.Create); + await bodyStream.CopyToAsync(streamToWriteTo); + } + + var unpackedDirectory = Path.Combine(Path.GetTempPath(), Path.GetFileNameWithoutExtension(Path.GetTempFileName())); + output.WriteLine($"Procdump downloaded. Unpacking to '{unpackedDirectory}'"); + System.IO.Compression.ZipFile.ExtractToDirectory(zipFilePath, unpackedDirectory); + + var executable = Environment.Is64BitProcess ? "procdump64.exe" : "procdump.exe"; + + _path = Path.Combine(unpackedDirectory, executable); + } + + public static bool CaptureMemoryDump(Process process, string outputFolder, ITestOutputHelper output = null) + { + if (!IsAvailable) + { + output.WriteLine("Procdump is not available..."); + return false; + } + + try + { + var args = $"-ma -accepteula {process.Id} {outputFolder}"; + return CaptureMemoryDump(args, output); + } + catch (Exception ex) + { + output.WriteLine("Error taking memory dump: " + ex); + return false; + } + } + + private static bool CaptureMemoryDump(string args, ITestOutputHelper output) + { + output.WriteLine($"Capturing memory dump using '{_path} {args}'"); + + using var dumpToolProcess = Process.Start(new ProcessStartInfo(_path, args) + { + UseShellExecute = false, + CreateNoWindow = true, + RedirectStandardOutput = true, + RedirectStandardError = true, + }); + + using var helper = new ProcessHelper(dumpToolProcess); + dumpToolProcess.WaitForExit(30_000); + helper.Drain(); + output.WriteLine($"[dump][stdout] {helper.StandardOutput}"); + output.WriteLine($"[dump][stderr] {helper.ErrorOutput}"); + + if (dumpToolProcess.ExitCode == 0) + { + output.WriteLine($"Memory dump successfully captured using '{_path} {args}'."); + } + else + { + output.WriteLine($"Failed to capture memory dump using '{_path} {args}'. Exit code was {dumpToolProcess.ExitCode}."); + } + + return true; + } + } +} diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/MockDatadogAgent.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/MockDatadogAgent.cs index fb24ae194959..22f44c9269d7 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/MockDatadogAgent.cs +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/MockDatadogAgent.cs @@ -20,21 +20,51 @@ public abstract class MockDatadogAgent : IDisposable { private readonly CancellationTokenSource _cancellationTokenSource = new(); private readonly ManualResetEventSlim _readinessNotifier = new(); + private AgentEtwProxy _etwProxy = null; public event EventHandler> ProfilerRequestReceived; public event EventHandler> TracerRequestReceived; public event EventHandler> TelemetryMetricsRequestReceived; + public event EventHandler> ProfilerRegistered; + public event EventHandler> EventsSent; + public event EventHandler> ProfilerUnregistered; public int NbCallsOnProfilingEndpoint { get; private set; } public bool IsReady => _readinessNotifier.Wait(TimeSpan.FromSeconds(30)); // wait for Agent being ready + public bool ProfilerHasRegistered { get => (_etwProxy != null) ? _etwProxy.ProfilerHasRegistered : false; } + + public bool ProfilerHasUnregistered { get => (_etwProxy != null) ? _etwProxy.ProfilerHasUnregistered : false; } + + public bool EventsHaveBeenSent { get => (_etwProxy != null) ? _etwProxy.EventsHaveBeenSent : false; } + protected ITestOutputHelper Output { get; set; } public static HttpAgent CreateHttpAgent(ITestOutputHelper output, int retries = 5) => new HttpAgent(output, retries); public static NamedPipeAgent CreateNamedPipeAgent(ITestOutputHelper output) => new NamedPipeAgent(output); + public void StartEtwProxy(ITestOutputHelper output, string namedPipeEndpoint, string eventsFilename = null) + { + // simulate the Agent as an ETW proxy to replay events (if any) + // 1. create a named pipe server with the given endpoint to receive registration/unregistration commands from the profiler + // --> keep track of the register/unregister to be able to validate the protocol in a test + // 2. read the events from the given file and send them to the profiler + // --> keep track of any error + // --> if no file is provided, don't send any event but accept registration/unregistration commands + // NOTE: this method must be called before calling Run() on the TestApplicationRunner + _etwProxy = new AgentEtwProxy(output, namedPipeEndpoint, eventsFilename); + _etwProxy.ProfilerRegistered += (sender, e) => ProfilerRegistered?.Invoke(this, e); + _etwProxy.EventsSent += (sender, e) => EventsSent?.Invoke(this, e); + _etwProxy.ProfilerUnregistered += (sender, e) => ProfilerUnregistered?.Invoke(this, e); + + Task.Run(() => _etwProxy.StartServerAsync()); + + // let the time for the server to start + Thread.Sleep(200); + } + public virtual void Dispose() { _cancellationTokenSource.Cancel(); @@ -175,7 +205,8 @@ private void HandleHttpRequests() // show only in error cases if ((message != null) && (NbCallsOnProfilingEndpoint < 2)) { - Console.WriteLine(message); + // NOTE: we can't use ITestOutputHelper here because it will throw an exception about missing current test + // Output.WriteLine(message); } } } diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/ProcessExtensions.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/ProcessExtensions.cs index 262bae4ad531..b8215e977c3a 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/ProcessExtensions.cs +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/ProcessExtensions.cs @@ -16,21 +16,55 @@ internal static class ProcessExtensions public static void TakeMemoryDump(this Process process, string outputFolderPath, ITestOutputHelper output) { + if (!EnvironmentHelper.IsRunningInCi()) + { + output.WriteLine("^^^^^^^^^^^^^^^^^^^^^^ Currently not running in Github Actions CI. No memory dump will be taken."); + return; + } + + output.WriteLine($"^^^^^^^^^^^^^^^^^^^^^^ Taking memory dump of process Id {process.Id}..."); + if (EnvironmentHelper.IsRunningOnWindows()) { - // TODO it for windows - output.WriteLine("No memory dump will be taken on Windows (for now)"); + TakeWindowsMemoryDump(process, outputFolderPath, output); return; } - if (!EnvironmentHelper.IsRunningInCi()) + TakeLinuxMemoryDump(process, outputFolderPath, output); + } + + public static void KillTree(this Process process) + { + Microsoft.Extensions.Internal.ProcessExtensions.KillTree(process); + } + + public static void GetAllThreadsStack(this Process process, string outputFolder, ITestOutputHelper output) + { + if (EnvironmentHelper.IsRunningOnWindows()) { - output.WriteLine("^^^^^^^^^^^^^^^^^^^^^^ Currently not running in Github Actions CI. No memory dump will be taken."); + output.WriteLine("^^^^^^^^^^^^^^^^^^^^^^^^^ For now cannot get callstack of all threads on Windows"); return; } - output.WriteLine($"^^^^^^^^^^^^^^^^^^^^^^ Taking memory dump of process Id {process.Id}..."); + Microsoft.Extensions.Internal.ProcessExtensions.RunProcessAndWaitForExit( + "gdb", + $"-p {process.Id} -batch -ex \"thread apply all bt\" -ex \"detach\" -ex \"quit\"", + TimeSpan.FromMinutes(1), + out var stdout); + + output.WriteLine("================ Debug"); + output.WriteLine(stdout); + File.WriteAllText($"{outputFolder}/parallel_stacks_{process.Id}", stdout); + } + + private static void TakeWindowsMemoryDump(this Process process, string outputFolderPath, ITestOutputHelper output) + { + MemoryDumpHelper.InitializeAsync(output).GetAwaiter().GetResult(); + MemoryDumpHelper.CaptureMemoryDump(process, outputFolderPath, output); + } + private static void TakeLinuxMemoryDump(this Process process, string outputFolderPath, ITestOutputHelper output) + { using var processDump = new Process(); var dotnetRuntimeFolder = Path.GetDirectoryName(typeof(object).Assembly.Location); @@ -82,29 +116,5 @@ public static void TakeMemoryDump(this Process process, string outputFolderPath, output.WriteLine($" Memory dump tool error: {Environment.NewLine}{errorOutput}"); } } - - public static void KillTree(this Process process) - { - Microsoft.Extensions.Internal.ProcessExtensions.KillTree(process); - } - - public static void GetAllThreadsStack(this Process process, string outputFolder, ITestOutputHelper output) - { - if (EnvironmentHelper.IsRunningOnWindows()) - { - output.WriteLine("^^^^^^^^^^^^^^^^^^^^^^^^^ For now cannot get callstack of all threads on Windows"); - return; - } - - Microsoft.Extensions.Internal.ProcessExtensions.RunProcessAndWaitForExit( - "gdb", - $"-p {process.Id} -batch -ex \"thread apply all bt\" -ex \"detach\" -ex \"quit\"", - TimeSpan.FromMinutes(1), - out var stdout); - - output.WriteLine("================ Debug"); - output.WriteLine(stdout); - File.WriteAllText($"{outputFolder}/parallel_stacks_{process.Id}", stdout); - } } } diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/RecordReader.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/RecordReader.cs new file mode 100644 index 000000000000..dbd238dc88ca --- /dev/null +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/RecordReader.cs @@ -0,0 +1,196 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; +using System.IO; +using System.Runtime.InteropServices; + +#pragma warning disable SA1649 // File name should match first type name + +namespace Datadog.Profiler.IntegrationTests +{ + // used for both register and unregister commands + [StructLayout(LayoutKind.Sequential, Pack = 1)] + public struct RegistrationCommand + { + public IpcHeader Header; + public UInt64 Pid; + } + + // Common part of each record | size = 17 + 80 + 2 = 99 + // The size of the CLR event payload byte[] is given by EtwUserDataLength + [StructLayout(LayoutKind.Sequential, Pack = 1)] + public struct AgentEventRecord + { + public IpcHeader Header; + public EVENT_HEADER EventHeader; + public UInt16 EtwUserDataLength; + + public AgentEventRecord() + { + EtwUserDataLength = 0; + } + } + + // TODO: check that it is possible to use .NET 8 InlineArray in integration tests + [System.Runtime.CompilerServices.InlineArray(14)] + public struct MagicVersion + { + public byte _element; + } + + [StructLayout(LayoutKind.Sequential, Pack = 1)] + public struct IpcHeader + { + public static UInt16 HeaderSize = 17; + public static string MagicValue = "DD_ETW_IPC_V1"; + + public MagicVersion Magic; // should be "DD_ETW_IPC_V1" in ASCII + public UInt16 Size; + public byte CommandIdOrResponseCode; + } + + public struct ClrEventPayload + { + public UInt16 EtwUserDataLength; + + // the size of this payload is given by EtwUserDataLength + public byte EtwPayload; // array of bytes + } + + // from C:\Program Files (x86)\Windows Kits\10\Include\10.0.19041.0\um\evntcons.h + [StructLayout(LayoutKind.Sequential, Pack = 1)] + public struct EVENT_RECORD + { + public EVENT_HEADER EventHeader; // Event header + public ETW_BUFFER_CONTEXT BufferContext; // Buffer context + public UInt16 ExtendedDataCount; // Number of extended data items + public UInt16 UserDataLength; // User data length + public UIntPtr ExtendedData; // Pointer to an array of extended data items + public UIntPtr UserData; // Pointer to user data + public UIntPtr UserContext; // Context from OpenTrace + } + + [StructLayout(LayoutKind.Sequential, Pack = 1)] + public struct EVENT_HEADER + { + public UInt16 Size; // Event Size + public UInt16 HeaderType; // Header Type + public UInt16 Flags; // Flags + public UInt16 EventProperty; // User given event property + public UInt32 ThreadId; // Thread Id + public UInt32 ProcessId; // Process Id + public UInt64 TimeStamp; // Event Timestamp + public Guid ProviderId; // Provider Id + public ETW_EVENT_DESCRIPTOR EventDescriptor; // Event Descriptor + public UInt32 KernelTime; // Kernel Mode CPU ticks + public UInt32 UserTime; // User mode CPU ticks + public Guid ActivityId; // Activity Id + } + + [StructLayout(LayoutKind.Sequential, Pack = 1)] + public struct ETW_BUFFER_CONTEXT + { + public byte ProcessorNumber; + public byte Alignment; + public UInt16 LoggerId; + } + + // from C:\Program Files (x86)\Windows Kits\10\Include\10.0.19041.0\shared\evntprov.h + [StructLayout(LayoutKind.Sequential, Pack = 1)] + public struct ETW_EVENT_DESCRIPTOR + { + public UInt16 Id; + public byte Version; + public byte Channel; + public byte Level; + public byte Opcode; + public UInt16 Task; + public UInt64 Keyword; + } + +#pragma warning disable SA1401 // Fields should be private +#pragma warning disable CA2211 // Non-constant fields should not be visible +#pragma warning disable SA1402 // File may only contain a single type + public static class AgentCommands + { + public static byte Register = 1; + public static byte Unregister = 2; + public static byte ClrEvent = 16; + public static byte KeepAlive = 17; + } + + public static class ResponseCodes + { + public static byte Success = 0; + public static byte Failure = 0xFF; + } +#pragma warning restore SA1402 // File may only contain a single type +#pragma warning restore CA2211 // Non-constant fields should not be visible +#pragma warning restore SA1401 // Fields should be private + + public class RecordReader + { + // IpcHeader + EVENT_HEADER + ClrEventPayload.Size + private const int CommonRecordSize = 17 + 80 + 2; // = 99 + private readonly BinaryReader _reader; + private readonly IRecordDumper _recordDumper; + private readonly IEventDumper _eventDumper; + private byte[] _recordBuffer; + + public RecordReader(BinaryReader reader, IRecordDumper recordDumper, IEventDumper eventDumper) + { + _reader = reader; + _recordDumper = recordDumper; + _eventDumper = eventDumper; + _recordBuffer = new byte[CommonRecordSize + 1024]; // + ClrEventPayload.EtwPayload max size + } + + // use a large buffer to read the record part by part + // but keep the record structure to send it as a whole to the dumper + // i.e.: + // - up to the ClrEventPayload could be stored as a struct mapped to the start of the buffer + // - the ClrEventPayload.EtwPayload could be passed as a Span mapped to the rest of read bytes in the buffer + public void ReadRecord() + { + // record = + // an IpcHeader + // a 80 bytes EVENT_HEADER (its Size field should be ignored) + // a ClrEventPayload (UInt16 EtwUserDataLength followed by byte[EtwUserDataLength value] EtwPayload) + // + // read the common part of the record + var sizeRead = _reader.Read(_recordBuffer, 0, CommonRecordSize); + var span = _recordBuffer.AsSpan(); + AgentEventRecord record = MemoryMarshal.Read(span); + + // read the rest of the record (i.e. CLR event payload) + sizeRead = _reader.Read(_recordBuffer, CommonRecordSize, record.EtwUserDataLength); + + if (_recordDumper != null) + { + _recordDumper.DumpRecord(_recordBuffer, CommonRecordSize + record.EtwUserDataLength); + } + + if (_eventDumper != null) + { + _eventDumper.DumpEvent( + record.EventHeader.TimeStamp, + record.EventHeader.ThreadId, + record.EventHeader.EventDescriptor.Version, + record.EventHeader.EventDescriptor.Keyword, + record.EventHeader.EventDescriptor.Level, + record.EventHeader.EventDescriptor.Id, + span.Slice(CommonRecordSize, record.EtwUserDataLength)); + } + } + + public Guid ReadGuid(BinaryReader reader) + { + byte[] guidBytes = reader.ReadBytes(16); + return new Guid(guidBytes); + } + } +} +#pragma warning restore SA1649 // File name should match first type name diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/TestApplicationRunner.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/TestApplicationRunner.cs index 98ce7ccd97ed..b397e785fe0d 100644 --- a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/TestApplicationRunner.cs +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/TestApplicationRunner.cs @@ -18,7 +18,7 @@ internal class TestApplicationRunner private readonly string _appName; private readonly string _framework; private readonly string _appAssembly; - private readonly ITestOutputHelper _output; + private readonly XUnitFileLogger _output; private readonly string _commandLine; private readonly string _testBaseOutputDir; @@ -42,8 +42,11 @@ public TestApplicationRunner( _framework = framework; Environment = new EnvironmentHelper(framework, enableTracer, enableProfiler); _testBaseOutputDir = Environment.GetTestOutputPath(); + var logPath = Path.Combine(_testBaseOutputDir, "logs"); + // create the log folder now instead of waiting for the profiler to create it + Directory.CreateDirectory(_testBaseOutputDir); _appAssembly = appAssembly; - _output = output; + _output = new XUnitFileLogger(output, Path.Combine(logPath, "xunit.txt")); _commandLine = commandLine ?? string.Empty; ServiceName = $"IntegrationTest-{_appName}"; } @@ -58,6 +61,8 @@ public TestApplicationRunner( public string ProcessOutput { get; set; } + public ITestOutputHelper XUnitLogger => _output; + public static string GetApplicationOutputFolderPath(string appName) { var configurationAndPlatform = $"{EnvironmentHelper.GetConfiguration()}-{EnvironmentHelper.GetPlatform()}"; diff --git a/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/XUnitFileLogger.cs b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/XUnitFileLogger.cs new file mode 100644 index 000000000000..150c95a584db --- /dev/null +++ b/profiler/test/Datadog.Profiler.IntegrationTests/Helpers/XUnitFileLogger.cs @@ -0,0 +1,54 @@ +// +// Unless explicitly stated otherwise all files in this repository are licensed under the Apache 2 License. +// This product includes software developed at Datadog (https://www.datadoghq.com/). Copyright 2022 Datadog, Inc. +// + +using System; +using System.IO; +using Xunit.Abstractions; + +namespace Datadog.Profiler.IntegrationTests.Helpers +{ + // This class wraps an xunit logger and save each line into a file corresponding to the current test + internal class XUnitFileLogger : ITestOutputHelper + { + private readonly string _filePath; + private readonly ITestOutputHelper _output; + + public XUnitFileLogger(ITestOutputHelper output, string filePath) + { + _output = output; + _filePath = filePath; + } + + // ITestOuputHelper interface implementation + public void WriteLine(string message) + { + _output.WriteLine(message); + WriteLineToFile(message); + } + + public void WriteLine(string format, params object[] args) + { + var message = string.Format(format, args); + _output.WriteLine(message); + WriteLineToFile(message); + } + + private void WriteLineToFile(string message) + { + // add the timestamp to allow correlation with other files such as profiler logs + string timestamp = DateTime.Now.ToString("[yyyy-MM-dd HH:mm:ss.fff] "); + try + { + using (var writer = new StreamWriter(_filePath, true)) + { + writer.WriteLine(string.Concat(timestamp, message)); + } + } + catch (Exception) + { + } + } + } +} diff --git a/profiler/test/Datadog.Profiler.Native.Tests/ConfigurationTest.cpp b/profiler/test/Datadog.Profiler.Native.Tests/ConfigurationTest.cpp index 5495e5769570..87ea3687928a 100644 --- a/profiler/test/Datadog.Profiler.Native.Tests/ConfigurationTest.cpp +++ b/profiler/test/Datadog.Profiler.Native.Tests/ConfigurationTest.cpp @@ -879,6 +879,24 @@ TEST_F(ConfigurationTest, CheckEtwIsDisabledIfEnvVarSetToFalse) ASSERT_THAT(configuration.IsEtwEnabled(), expectedValue); } +TEST_F(ConfigurationTest, CheckEtwReplayEndpointIsEmptyIfEnvVarNotSet) +{ + auto configuration = Configuration{}; + std::string expectedValue = ""; + ASSERT_THAT(configuration.GetEtwReplayEndpoint(), expectedValue); +} + +// Windows named pipe paths are not supported on Linux +#ifndef LINUX +TEST_F(ConfigurationTest, CheckEtwReplayEndpointIfEnvVarIsSet) +{ + EnvironmentHelper::EnvironmentVariable ar(EnvironmentVariables::EtwReplayEndpoint, WStr("\\\\.\\pipe\\DD_ETW_FOR_TEST")); + auto configuration = Configuration{}; + std::string expectedValue = "\\\\.\\pipe\\DD_ETW_FOR_TEST"; + ASSERT_THAT(configuration.GetEtwReplayEndpoint(), expectedValue); +} +#endif + TEST_F(ConfigurationTest, CheckSsiNotDeployedByDefault) { auto configuration = Configuration{}; diff --git a/profiler/test/Datadog.Profiler.Native.Tests/ProfilerMockedInterface.h b/profiler/test/Datadog.Profiler.Native.Tests/ProfilerMockedInterface.h index 333fbb9ceb57..afdc20d9e767 100644 --- a/profiler/test/Datadog.Profiler.Native.Tests/ProfilerMockedInterface.h +++ b/profiler/test/Datadog.Profiler.Native.Tests/ProfilerMockedInterface.h @@ -76,6 +76,7 @@ class MockConfiguration : public IConfiguration MOCK_METHOD(EnablementStatus, GetEnablementStatus, (), (const override)); MOCK_METHOD(DeploymentMode, GetDeploymentMode, (), (const override)); MOCK_METHOD(bool, IsEtwLoggingEnabled, (), (const override)); + MOCK_METHOD(std::string const&, GetEtwReplayEndpoint, (), (const override)); MOCK_METHOD(CpuProfilerType, GetCpuProfilerType, (), (const override)); MOCK_METHOD(std::chrono::milliseconds, GetCpuProfilingInterval, (), (const override)); MOCK_METHOD(std::chrono::milliseconds, GetSsiLongLivedThreshold, (), (const override)); diff --git a/tracer/build/_build/Build.Steps.cs b/tracer/build/_build/Build.Steps.cs index 96a5dc4c6ac8..ed34d21e59df 100644 --- a/tracer/build/_build/Build.Steps.cs +++ b/tracer/build/_build/Build.Steps.cs @@ -669,12 +669,12 @@ async Task DownloadWafVersion(string libddwafVersion = null, string uncompressFo .SetOutput(MonitoringHomeDirectory / targetFramework) ); }); - + Target PublishNativeSymbolsWindows => _ => _ .Unlisted() .OnlyWhenStatic(() => IsWin) .After(CompileTracerNativeSrc, PublishManagedTracer) - .Executes(() => + .Executes(() => { foreach (var architecture in ArchitecturesForPlatformForTracer) { @@ -757,7 +757,7 @@ async Task DownloadWafVersion(string libddwafVersion = null, string uncompressFo { // We don't produce an x86-only MSI any more var architectures = ArchitecturesForPlatformForTracer.Where(x => x != MSBuildTargetPlatform.x86); - + MSBuild(s => s .SetTargetPath(SharedDirectory / "src" / "msi-installer" / "WindowsInstaller.wixproj") .SetConfiguration(BuildConfiguration) @@ -985,7 +985,7 @@ found in `/usr/share/common-licenses/Apache-2.0'. homepage: "https://github.com/DataDog/dd-trace-dotnet" # We were previously using "Apache License 2.0" but that's not technically correct # As needs to be one of the standard fedora licences here: https://docs.fedoraproject.org/en-US/legal/allowed-licenses/ - # and is not used directly by the deb package format: https://www.debian.org/doc/debian-policy/ch-docs.html + # and is not used directly by the deb package format: https://www.debian.org/doc/debian-policy/ch-docs.html license: "Apache-2.0" priority: extra section: default @@ -995,8 +995,8 @@ found in `/usr/share/common-licenses/Apache-2.0'. rpm: # The package group. This option is deprecated by most distros # but we added it with fpm, so keeping it here for consistency - group: default - prefixes: + group: default + prefixes: - /opt/datadog contents: - src: {assetsDirectory}/ @@ -2615,10 +2615,10 @@ string NormalizedPath(AbsolutePath ap) // This one is caused by the intentional crash in the crash tracking smoke test knownPatterns.Add(new("Application threw an unhandled exception: System.BadImageFormatException: Expected", RegexOptions.Compiled)); - // We intentionally set the variables for smoke tests which means we get this warning on <= .NET Core 3.0 or <.NET 6.0.12 + // We intentionally set the variables for smoke tests which means we get this warning on <= .NET Core 3.0 or <.NET 6.0.12 knownPatterns.Add(new(".*SingleStepGuardRails::ShouldForceInstrumentationOverride: Found incompatible runtime .NET Core 3.0 or lower", RegexOptions.Compiled)); knownPatterns.Add(new(".*SingleStepGuardRails::ShouldForceInstrumentationOverride: Found incompatible runtime .NET 6.0.12 and earlier have known crashing bugs", RegexOptions.Compiled)); - + // CI Visibility known errors knownPatterns.Add(new(@".*The Git repository couldn't be automatically extracted.*", RegexOptions.Compiled)); knownPatterns.Add(new(@".*DD_GIT_REPOSITORY_URL is set with.*", RegexOptions.Compiled)); @@ -2670,7 +2670,7 @@ private void CheckLogsForErrors(List knownPatterns, bool allFilesMustExis var hasRequiredFiles = !allFilesMustExist || (managedFiles.Count > 0 && nativeTracerFiles.Count > 0 - && (nativeProfilerFiles.Count > 0 || IsOsx) // profiler doesn't support mac + && (nativeProfilerFiles.Count > 0 || IsOsx) // profiler doesn't support mac && nativeLoaderFiles.Count > 0); if (hasRequiredFiles @@ -2989,7 +2989,7 @@ private void CopyDumpsTo(AbsolutePath root) { Logger.Information("Moving file '{Dump}' to '{Root}'", dump, dumpFolder); - MoveFileToDirectory(dump, dumpFolder, FileExistsPolicy.Overwrite); + CopyFileToDirectory(dump, dumpFolder, FileExistsPolicy.OverwriteIfNewer); } } @@ -3030,7 +3030,7 @@ protected override void OnTargetRunning(string target) Logger.Information($"Drive space available on '{drive.Name}': {PrettyPrint(drive.AvailableFreeSpace)} / {PrettyPrint(drive.TotalSize)}"); } } - + // set variables for subsequent tests var isSsiRun = Environment.GetEnvironmentVariable("IS_SSI_RUN"); if (!string.IsNullOrEmpty(isSsiRun) && string.Equals(isSsiRun, "true", StringComparison.OrdinalIgnoreCase))