Reland "Recording timing info in trace events when D3D12 queue submit"

This is a reland of 8e9fbbe7ca

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. All Windows APIs used here are supported since Windows
2000.

Original change's description:
> 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>

Bug: dawn:1264
Change-Id: I3f81a76726f88fc0e9d817bfe452a050583399e8
Reviewed-on: https://dawn-review.googlesource.com/c/dawn/+/78252
Reviewed-by: Yuly Novikov <ynovikov@google.com>
Reviewed-by: Kai Ninomiya <kainino@chromium.org>
Commit-Queue: Zhaoming Jiang <zhaoming.jiang@intel.com>
This commit is contained in:
Zhaoming Jiang 2022-01-26 13:34:51 +00:00 committed by Dawn LUCI CQ
parent 7fd3676de7
commit 3d3e1757c4
3 changed files with 52 additions and 0 deletions

View File

@ -230,6 +230,13 @@ namespace dawn::native {
"Enable optimizations when compiling with FXC. Disabled by default because FXC " "Enable optimizations when compiling with FXC. Disabled by default because FXC "
"miscompiles in many cases when optimizations are enabled.", "miscompiles in many cases when optimizations are enabled.",
"https://crbug.com/dawn/1203"}}, "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. // Dummy comment to separate the }} so it is clearer what to copy-paste to add a toggle.
}}; }};

View File

@ -61,6 +61,7 @@ namespace dawn::native {
DisableR8RG8Mipmaps, DisableR8RG8Mipmaps,
UseDummyFragmentInVertexOnlyPipeline, UseDummyFragmentInVertexOnlyPipeline,
FxcOptimizations, FxcOptimizations,
RecordDetailedTimingInTraceEvents,
EnumCount, EnumCount,
InvalidEnum = EnumCount, InvalidEnum = EnumCount,

View File

@ -12,11 +12,17 @@
// See the License for the specific language governing permissions and // See the License for the specific language governing permissions and
// limitations under the License. // limitations under the License.
#include "dawn_native/d3d12/CommandRecordingContext.h" #include "dawn_native/d3d12/CommandRecordingContext.h"
#include "dawn_native/d3d12/CommandAllocatorManager.h" #include "dawn_native/d3d12/CommandAllocatorManager.h"
#include "dawn_native/d3d12/D3D12Error.h" #include "dawn_native/d3d12/D3D12Error.h"
#include "dawn_native/d3d12/DeviceD3D12.h" #include "dawn_native/d3d12/DeviceD3D12.h"
#include "dawn_native/d3d12/HeapD3D12.h" #include "dawn_native/d3d12/HeapD3D12.h"
#include "dawn_native/d3d12/ResidencyManagerD3D12.h" #include "dawn_native/d3d12/ResidencyManagerD3D12.h"
#include "dawn_platform/DawnPlatform.h"
#include "dawn_platform/tracing/TraceEvent.h"
#include <profileapi.h>
#include <sysinfoapi.h>
namespace dawn::native::d3d12 { namespace dawn::native::d3d12 {
@ -74,6 +80,44 @@ namespace dawn::native::d3d12 {
DAWN_TRY(device->GetResidencyManager()->EnsureHeapsAreResident( DAWN_TRY(device->GetResidencyManager()->EnsureHeapsAreResident(
mHeapsPendingUsage.data(), mHeapsPendingUsage.size())); mHeapsPendingUsage.data(), mHeapsPendingUsage.size()));
if (device->IsToggleEnabled(Toggle::RecordDetailedTimingInTraceEvents)) {
uint64_t gpuTimestamp;
uint64_t cpuTimestamp;
FILETIME fileTimeNonPrecise;
SYSTEMTIME systemTimeNonPrecise;
// Both supported since Windows 2000, have a accuracy of 1ms
GetSystemTimeAsFileTime(&fileTimeNonPrecise);
GetSystemTime(&systemTimeNonPrecise);
// Query CPU and GPU timestamps at almost the same time
device->GetCommandQueue()->GetClockCalibration(&gpuTimestamp, &cpuTimestamp);
uint64_t gpuFrequency;
uint64_t cpuFrequency;
LARGE_INTEGER cpuFrequencyLargeInteger;
device->GetCommandQueue()->GetTimestampFrequency(&gpuFrequency);
QueryPerformanceFrequency(
&cpuFrequencyLargeInteger); // Supported since Windows 2000
cpuFrequency = cpuFrequencyLargeInteger.QuadPart;
std::string timingInfo = absl::StrFormat(
"UTC Time: %u/%u/%u %02u:%02u:%02u.%03u, File Time: %u, CPU "
"Timestamp: %u, GPU Timestamp: %u, CPU Tick Frequency: %u, GPU Tick Frequency: "
"%u",
systemTimeNonPrecise.wYear, systemTimeNonPrecise.wMonth,
systemTimeNonPrecise.wDay, systemTimeNonPrecise.wHour,
systemTimeNonPrecise.wMinute, systemTimeNonPrecise.wSecond,
systemTimeNonPrecise.wMilliseconds,
(static_cast<uint64_t>(fileTimeNonPrecise.dwHighDateTime) << 32) +
fileTimeNonPrecise.dwLowDateTime,
cpuTimestamp, gpuTimestamp, cpuFrequency, gpuFrequency);
TRACE_EVENT_INSTANT1(
device->GetPlatform(), General,
"d3d12::CommandRecordingContext::ExecuteCommandList Detailed Timing", "Timing",
timingInfo.c_str());
}
ID3D12CommandList* d3d12CommandList = GetCommandList(); ID3D12CommandList* d3d12CommandList = GetCommandList();
device->GetCommandQueue()->ExecuteCommandLists(1, &d3d12CommandList); device->GetCommandQueue()->ExecuteCommandLists(1, &d3d12CommandList);