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 <enga@chromium.org>
Commit-Queue: Shaobo Yan <shaobo.yan@intel.com>

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 <cstdio>
 #include <cstring>
@@ -35,7 +37,9 @@ namespace dawn::native {
             MapRequestTask(Ref<BufferBase> 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<MapRequestTask> request =
             std::make_unique<MapRequestTask>(this, mLastMapID);
+        TRACE_EVENT1(GetDevice()->GetPlatform(), General, "Buffer::APIMapAsync", "serial",
+                     uint64_t(GetDevice()->GetPendingCommandSerial()));
         GetDevice()->GetQueue()->TrackTask(std::move(request),
                                            GetDevice()->GetPendingCommandSerial());
     }

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();
     }
 

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<TaskInFlight> 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<std::unique_ptr<TaskInFlight>> 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);
         }
     }
 

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;
         };
 

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));
 

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 <sstream>
 
@@ -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");

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,
+        TRACE_EVENT_BEGIN1(GetDevice()->GetPlatform(), Recording,
-                           "CommandBufferD3D12::RecordCommands");
+                           "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,
+        TRACE_EVENT_END1(GetDevice()->GetPlatform(), Recording,
-                         "CommandBufferD3D12::RecordCommands");
+                         "CommandBufferD3D12::RecordCommands", "serial",
+                         uint64_t(GetDevice()->GetPendingCommandSerial()));
 
         DAWN_TRY(device->ExecutePendingCommandContext());
 

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)