From e4c799071ba514ba520411fcc2d8975536522164 Mon Sep 17 00:00:00 2001 From: Shaobo Date: Tue, 19 Apr 2022 00:25:34 +0000 Subject: [PATCH] Add Debug Tracing in Dawn Add more trace event in Dawn to better understand workflow in Dawn. These trace events focus on tick() and MapAsync() related in flight task. Bug: dawn:1335 Change-Id: Iac35959f315c221c8539137efbf35039458a6f77 Reviewed-on: https://dawn-review.googlesource.com/c/dawn/+/86620 Reviewed-by: Austin Eng Commit-Queue: Shaobo Yan --- src/dawn/native/Buffer.cpp | 8 +++++++- src/dawn/native/Device.cpp | 4 ++++ src/dawn/native/Queue.cpp | 12 ++++++++++-- src/dawn/native/Queue.h | 4 +++- src/dawn/native/d3d12/BufferD3D12.cpp | 4 ++++ src/dawn/native/d3d12/DeviceD3D12.cpp | 5 +++++ src/dawn/native/d3d12/QueueD3D12.cpp | 10 ++++++---- src/dawn/platform/tracing/TraceEvent.h | 1 + 8 files changed, 40 insertions(+), 8 deletions(-) diff --git a/src/dawn/native/Buffer.cpp b/src/dawn/native/Buffer.cpp index f324597401..79a1bfaae2 100644 --- a/src/dawn/native/Buffer.cpp +++ b/src/dawn/native/Buffer.cpp @@ -23,6 +23,8 @@ #include "dawn/native/ObjectType_autogen.h" #include "dawn/native/Queue.h" #include "dawn/native/ValidationUtils_autogen.h" +#include "dawn/platform/DawnPlatform.h" +#include "dawn/platform/tracing/TraceEvent.h" #include #include @@ -35,7 +37,9 @@ namespace dawn::native { MapRequestTask(Ref buffer, MapRequestID id) : buffer(std::move(buffer)), id(id) { } - void Finish() override { + void Finish(dawn::platform::Platform* platform, ExecutionSerial serial) override { + TRACE_EVENT1(platform, General, "Buffer::TaskInFlight::Finished", "serial", + uint64_t(serial)); buffer->OnMapRequestCompleted(id, WGPUBufferMapAsyncStatus_Success); } void HandleDeviceLoss() override { @@ -350,6 +354,8 @@ namespace dawn::native { } std::unique_ptr request = std::make_unique(this, mLastMapID); + TRACE_EVENT1(GetDevice()->GetPlatform(), General, "Buffer::APIMapAsync", "serial", + uint64_t(GetDevice()->GetPendingCommandSerial())); GetDevice()->GetQueue()->TrackTask(std::move(request), GetDevice()->GetPendingCommandSerial()); } diff --git a/src/dawn/native/Device.cpp b/src/dawn/native/Device.cpp index 22dd2b90d7..b032a6b510 100644 --- a/src/dawn/native/Device.cpp +++ b/src/dawn/native/Device.cpp @@ -1158,6 +1158,10 @@ namespace dawn::native { if (IsLost() || ConsumedError(Tick())) { return false; } + + TRACE_EVENT1(GetPlatform(), General, "DeviceBase::APITick::IsDeviceIdle", "isDeviceIdle", + IsDeviceIdle()); + return !IsDeviceIdle(); } diff --git a/src/dawn/native/Queue.cpp b/src/dawn/native/Queue.cpp index 919f554c9c..8b17a80cb5 100644 --- a/src/dawn/native/Queue.cpp +++ b/src/dawn/native/Queue.cpp @@ -135,8 +135,10 @@ namespace dawn::native { SubmittedWorkDone(WGPUQueueWorkDoneCallback callback, void* userdata) : mCallback(callback), mUserdata(userdata) { } - void Finish() override { + void Finish(dawn::platform::Platform* platform, ExecutionSerial serial) override { ASSERT(mCallback != nullptr); + TRACE_EVENT1(platform, General, "Queue::SubmittedWorkDone::Finished", "serial", + uint64_t(serial)); mCallback(WGPUQueueWorkDoneStatus_Success, mUserdata); mCallback = nullptr; } @@ -220,6 +222,9 @@ namespace dawn::native { // commands (this is non-observable outside of tests so it's ok to do deviate a bit from the // spec). TrackTask(std::move(task), GetDevice()->GetPendingCommandSerial()); + + TRACE_EVENT1(GetDevice()->GetPlatform(), General, "Queue::APIOnSubmittedWorkDone", "serial", + uint64_t(GetDevice()->GetPendingCommandSerial())); } void QueueBase::TrackTask(std::unique_ptr task, ExecutionSerial serial) { @@ -233,6 +238,9 @@ namespace dawn::native { // To prevent the reentrant call from invalidating mTasksInFlight while in use by the first // call, we remove the tasks to finish from the queue, update mTasksInFlight, then run the // callbacks. + TRACE_EVENT1(GetDevice()->GetPlatform(), General, "Queue::Tick", "finishedSerial", + uint64_t(finishedSerial)); + std::vector> tasks; for (auto& task : mTasksInFlight.IterateUpTo(finishedSerial)) { tasks.push_back(std::move(task)); @@ -240,7 +248,7 @@ namespace dawn::native { mTasksInFlight.ClearUpTo(finishedSerial); for (auto& task : tasks) { - task->Finish(); + task->Finish(GetDevice()->GetPlatform(), finishedSerial); } } diff --git a/src/dawn/native/Queue.h b/src/dawn/native/Queue.h index cb2f0183d6..fa186cf07e 100644 --- a/src/dawn/native/Queue.h +++ b/src/dawn/native/Queue.h @@ -21,7 +21,9 @@ #include "dawn/native/IntegerTypes.h" #include "dawn/native/ObjectBase.h" +#include "dawn/native/DawnNative.h" #include "dawn/native/dawn_platform.h" +#include "dawn/platform/DawnPlatform.h" namespace dawn::native { @@ -29,7 +31,7 @@ namespace dawn::native { public: struct TaskInFlight { virtual ~TaskInFlight(); - virtual void Finish() = 0; + virtual void Finish(dawn::platform::Platform* platform, ExecutionSerial serial) = 0; virtual void HandleDeviceLoss() = 0; }; diff --git a/src/dawn/native/d3d12/BufferD3D12.cpp b/src/dawn/native/d3d12/BufferD3D12.cpp index 84fbbb67c7..4b8fc6b5ad 100644 --- a/src/dawn/native/d3d12/BufferD3D12.cpp +++ b/src/dawn/native/d3d12/BufferD3D12.cpp @@ -25,6 +25,8 @@ #include "dawn/native/d3d12/HeapD3D12.h" #include "dawn/native/d3d12/ResidencyManagerD3D12.h" #include "dawn/native/d3d12/UtilsD3D12.h" +#include "dawn/platform/DawnPlatform.h" +#include "dawn/platform/tracing/TraceEvent.h" namespace dawn::native::d3d12 { @@ -320,6 +322,8 @@ namespace dawn::native::d3d12 { const char* contextInfo) { // The mapped buffer can be accessed at any time, so it must be locked to ensure it is never // evicted. This buffer should already have been made resident when it was created. + TRACE_EVENT0(GetDevice()->GetPlatform(), General, "BufferD3D12::MapInternal"); + Heap* heap = ToBackend(mResourceAllocation.GetResourceHeap()); DAWN_TRY(ToBackend(GetDevice())->GetResidencyManager()->LockAllocation(heap)); diff --git a/src/dawn/native/d3d12/DeviceD3D12.cpp b/src/dawn/native/d3d12/DeviceD3D12.cpp index 6b77b3a07a..409089018e 100644 --- a/src/dawn/native/d3d12/DeviceD3D12.cpp +++ b/src/dawn/native/d3d12/DeviceD3D12.cpp @@ -41,6 +41,8 @@ #include "dawn/native/d3d12/StagingDescriptorAllocatorD3D12.h" #include "dawn/native/d3d12/SwapChainD3D12.h" #include "dawn/native/d3d12/UtilsD3D12.h" +#include "dawn/platform/DawnPlatform.h" +#include "dawn/platform/tracing/TraceEvent.h" #include @@ -339,6 +341,9 @@ namespace dawn::native::d3d12 { MaybeError Device::NextSerial() { IncrementLastSubmittedCommandSerial(); + TRACE_EVENT1(GetPlatform(), General, "D3D12Device::SignalFence", "serial", + uint64_t(GetLastSubmittedCommandSerial())); + return CheckHRESULT( mCommandQueue->Signal(mFence.Get(), uint64_t(GetLastSubmittedCommandSerial())), "D3D12 command queue signal fence"); diff --git a/src/dawn/native/d3d12/QueueD3D12.cpp b/src/dawn/native/d3d12/QueueD3D12.cpp index f6e6c2ea5b..19b6ac5091 100644 --- a/src/dawn/native/d3d12/QueueD3D12.cpp +++ b/src/dawn/native/d3d12/QueueD3D12.cpp @@ -50,13 +50,15 @@ namespace dawn::native::d3d12 { CommandRecordingContext* commandContext; DAWN_TRY_ASSIGN(commandContext, device->GetPendingCommandContext()); - TRACE_EVENT_BEGIN0(GetDevice()->GetPlatform(), Recording, - "CommandBufferD3D12::RecordCommands"); + TRACE_EVENT_BEGIN1(GetDevice()->GetPlatform(), Recording, + "CommandBufferD3D12::RecordCommands", "serial", + uint64_t(GetDevice()->GetPendingCommandSerial())); for (uint32_t i = 0; i < commandCount; ++i) { DAWN_TRY(ToBackend(commands[i])->RecordCommands(commandContext)); } - TRACE_EVENT_END0(GetDevice()->GetPlatform(), Recording, - "CommandBufferD3D12::RecordCommands"); + TRACE_EVENT_END1(GetDevice()->GetPlatform(), Recording, + "CommandBufferD3D12::RecordCommands", "serial", + uint64_t(GetDevice()->GetPendingCommandSerial())); DAWN_TRY(device->ExecutePendingCommandContext()); diff --git a/src/dawn/platform/tracing/TraceEvent.h b/src/dawn/platform/tracing/TraceEvent.h index 0baf98fb85..2dc1351296 100644 --- a/src/dawn/platform/tracing/TraceEvent.h +++ b/src/dawn/platform/tracing/TraceEvent.h @@ -857,6 +857,7 @@ namespace dawn::platform::TraceEvent { } INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned long long, TRACE_VALUE_TYPE_UINT) + INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned long, TRACE_VALUE_TYPE_UINT) INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned int, TRACE_VALUE_TYPE_UINT) INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned short, TRACE_VALUE_TYPE_UINT) INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned char, TRACE_VALUE_TYPE_UINT)