commit 8e9fbbe7caa414f7006d0568d918561b5ca9a94f
author Zhaoming Jiang <zhaoming.jiang@intel.com> Tue Jan 25 01:40:44 2022 +0000
committer Dawn LUCI CQ <dawn-scoped@luci-project-accounts.iam.gserviceaccount.com> Tue Jan 25 01:40:44 2022 +0000
tree a062c8e5f4a66eff7c9c081a994ffa467b06dd7b
parent 778cf0412625ea1f2eb2e63667d5dcc0a658b07d

Recording timing info in trace events when D3D12 queue submit

Add a toggle RecordDetailedTimingInTraceEvents. When this toggle is
enabled, record detailed timing information in trace events right
before calling ExecuteCommandLists on a D3D12 command queue, and the
information includes system time, CPU timestamp, GPU timestamp, and
their frequency.

Bug: dawn:1264
Change-Id: Ie06d3f2b7eb25c641ee00476334bd276227c3678
Reviewed-on: https://dawn-review.googlesource.com/c/dawn/+/77381
Reviewed-by: Corentin Wallez <cwallez@chromium.org>
Commit-Queue: Zhaoming Jiang <zhaoming.jiang@intel.com>

src/dawn_native/Toggles.cpp

diff --git a/src/dawn_native/Toggles.cpp b/src/dawn_native/Toggles.cpp
index 63dcdda..757d4ff 100644
--- a/src/dawn_native/Toggles.cpp
+++ b/src/dawn_native/Toggles.cpp
@@ -230,6 +230,13 @@
               "Enable optimizations when compiling with FXC. Disabled by default because FXC "
               "miscompiles in many cases when optimizations are enabled.",
               "https://crbug.com/dawn/1203"}},
+            {Toggle::RecordDetailedTimingInTraceEvents,
+             {"record_detailed_timing_in_trace_events",
+              "Record detailed timing information in trace events at certain point. Currently the "
+              "timing information is recorded right before calling ExecuteCommandLists on a D3D12 "
+              "command queue, and the information includes system time, CPU timestamp, GPU "
+              "timestamp, and their frequency.",
+              "https://crbug.com/dawn/1264"}},
 
             // Dummy comment to separate the }} so it is clearer what to copy-paste to add a toggle.
         }};

src/dawn_native/Toggles.h

diff --git a/src/dawn_native/Toggles.h b/src/dawn_native/Toggles.h
index 0fc748f..5b7e97c 100644
--- a/src/dawn_native/Toggles.h
+++ b/src/dawn_native/Toggles.h
@@ -61,6 +61,7 @@
         DisableR8RG8Mipmaps,
         UseDummyFragmentInVertexOnlyPipeline,
         FxcOptimizations,
+        RecordDetailedTimingInTraceEvents,
 
         EnumCount,
         InvalidEnum = EnumCount,

src/dawn_native/d3d12/CommandRecordingContext.cpp

diff --git a/src/dawn_native/d3d12/CommandRecordingContext.cpp b/src/dawn_native/d3d12/CommandRecordingContext.cpp
index 6749c2c..f6f0010 100644
--- a/src/dawn_native/d3d12/CommandRecordingContext.cpp
+++ b/src/dawn_native/d3d12/CommandRecordingContext.cpp
@@ -12,11 +12,18 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 #include "dawn_native/d3d12/CommandRecordingContext.h"
+
 #include "dawn_native/d3d12/CommandAllocatorManager.h"
 #include "dawn_native/d3d12/D3D12Error.h"
 #include "dawn_native/d3d12/DeviceD3D12.h"
 #include "dawn_native/d3d12/HeapD3D12.h"
 #include "dawn_native/d3d12/ResidencyManagerD3D12.h"
+#include "dawn_platform/DawnPlatform.h"
+#include "dawn_platform/tracing/TraceEvent.h"
+
+#include <profileapi.h>
+#include <sysinfoapi.h>
+#include <timezoneapi.h>
 
 namespace dawn::native::d3d12 {
 
@@ -74,6 +81,42 @@
             DAWN_TRY(device->GetResidencyManager()->EnsureHeapsAreResident(
                 mHeapsPendingUsage.data(), mHeapsPendingUsage.size()));
 
+            if (device->IsToggleEnabled(Toggle::RecordDetailedTimingInTraceEvents)) {
+                // We assume that all WIN32 APIs used here are available. Windows 8 or above support
+                // all of them, and using D3D12 requires Windows 10 or above, so it should be safe.
+                FILETIME systemTimePrecise;
+                uint64_t gpuTimestamp;
+                uint64_t cpuTimestamp;
+
+                GetSystemTimePreciseAsFileTime(&systemTimePrecise);
+                device->GetCommandQueue()->GetClockCalibration(&gpuTimestamp, &cpuTimestamp);
+
+                uint64_t gpuFrequency;
+                uint64_t cpuFrequency;
+                LARGE_INTEGER cpuFrequencyLargeInteger;
+                device->GetCommandQueue()->GetTimestampFrequency(&gpuFrequency);
+                QueryPerformanceFrequency(&cpuFrequencyLargeInteger);
+                cpuFrequency = cpuFrequencyLargeInteger.QuadPart;
+
+                SYSTEMTIME systemTime;
+                FileTimeToSystemTime(&systemTimePrecise, &systemTime);
+
+                std::string timingInfo = absl::StrFormat(
+                    "Time of Day: %u/%u/%u %02u:%02u:%02u.%03u, Precise System Time: %u, CPU "
+                    "Timestamp: %u, GPU Timestamp: %u, CPU Tick Frequency: %u, GPU Tick Frequency: "
+                    "%u",
+                    systemTime.wYear, systemTime.wMonth, systemTime.wDay, systemTime.wHour,
+                    systemTime.wMinute, systemTime.wSecond, systemTime.wMilliseconds,
+                    (static_cast<uint64_t>(systemTimePrecise.dwHighDateTime) << 32) +
+                        systemTimePrecise.dwLowDateTime,
+                    cpuTimestamp, gpuTimestamp, cpuFrequency, gpuFrequency);
+
+                TRACE_EVENT_INSTANT1(
+                    device->GetPlatform(), General,
+                    "d3d12::CommandRecordingContext::ExecuteCommandList Detailed Timing", "Timing",
+                    timingInfo.c_str());
+            }
+
             ID3D12CommandList* d3d12CommandList = GetCommandList();
             device->GetCommandQueue()->ExecuteCommandLists(1, &d3d12CommandList);