[host] measure ready time at framebuffer publication

Exclude command queue reset and cleanup from the ready stage, and keep
the wall-clock residual only as the legacy timing fallback.
This commit is contained in:
Geoffrey McRae
2026-08-03 16:22:07 +10:00
parent aa289fa022
commit 24be0a8869
16 changed files with 157 additions and 67 deletions

View File

@@ -97,6 +97,7 @@ typedef struct LG_TransportFrameTiming
uint64_t captureTime;
uint64_t postProcessTime;
uint64_t copyTime;
uint64_t readyTime;
}
LG_TransportFrameTiming;

View File

@@ -205,6 +205,7 @@ struct RenderTiming
uint64_t captureTime;
uint64_t postProcessTime;
uint64_t copyTime;
uint64_t readyTime;
uint64_t importTime;
};
@@ -225,6 +226,8 @@ static struct RenderTiming frameTimingLoad(void)
&g_state.producerPostProcessTime, memory_order_seq_cst);
timing.copyTime = atomic_load_explicit(
&g_state.producerCopyTime, memory_order_seq_cst);
timing.readyTime = atomic_load_explicit(
&g_state.producerReadyTime, memory_order_seq_cst);
timing.importTime = atomic_load_explicit(
&g_state.clientImportTime, memory_order_seq_cst);
@@ -245,6 +248,8 @@ static void frameTimingStore(const LG_TransportFrameTiming * timing,
timing->postProcessTime, memory_order_seq_cst);
atomic_store_explicit(&g_state.producerCopyTime,
timing->copyTime, memory_order_seq_cst);
atomic_store_explicit(&g_state.producerReadyTime,
timing->readyTime, memory_order_seq_cst);
atomic_store_explicit(&g_state.clientImportTime,
importTime, memory_order_seq_cst);
atomic_fetch_add_explicit(
@@ -257,13 +262,14 @@ static void preSwapCallback(void * udata)
const uint64_t timestamp = nanotime();
const uint64_t renderTime = timestamp - timing->renderStart;
if (timing->captureTime || timing->postProcessTime || timing->copyTime ||
timing->importTime)
timing->readyTime || timing->importTime)
{
const OverlayFrameTiming frameTiming = {
.timestamp = timestamp,
.capture = timing->captureTime * 1e-6f,
.postProcess = timing->postProcessTime * 1e-6f,
.copy = timing->copyTime * 1e-6f,
.ready = timing->readyTime * 1e-6f,
.import = timing->importTime * 1e-6f,
.render = renderTime * 1e-6f,
};

View File

@@ -154,6 +154,7 @@ struct AppState
atomic_uint_least64_t producerCaptureTime;
atomic_uint_least64_t producerPostProcessTime;
atomic_uint_least64_t producerCopyTime;
atomic_uint_least64_t producerReadyTime;
atomic_uint_least64_t clientImportTime;
atomic_uint_least64_t renderCount, frameCount;
_Atomic(float) fps, ups;

View File

@@ -179,7 +179,7 @@ static bool rbCalcMetrics(int index, void * value_, void * udata_)
#define TIMING_PLOT_WINDOW_NS 20000000000ULL
#define TIMING_PLOT_BUCKET_NS \
(TIMING_PLOT_WINDOW_NS / TIMING_PLOT_BUCKETS)
#define TIMING_STAGE_COUNT 5
#define TIMING_STAGE_COUNT 6
struct TimingPlotData
{
@@ -239,6 +239,7 @@ static bool accumulateTimingSample(int index, void * value_, void * udata_)
timing->capture,
timing->postProcess,
timing->copy,
timing->ready,
timing->import,
timing->render,
};
@@ -349,6 +350,7 @@ static void renderTimingStatistic(struct OverlayGraph * graph,
"Capture",
"Post",
"Copy",
"Ready",
"Import",
"Render",
};

View File

@@ -50,6 +50,7 @@ typedef struct OverlayFrameTiming
float capture;
float postProcess;
float copy;
float ready;
float import;
float render;
}

View File

@@ -136,6 +136,7 @@ int main(void)
wireFrame->captureTime = 100;
wireFrame->postProcessTime = 200;
wireFrame->copyTime = 300;
wireFrame->readyTime = 400;
wireFrame->timingSerial = wireFrame->frameSerial;
wireFrame->timingValid = 1;
FrameBuffer * framebuffer = (FrameBuffer *)((uint8_t *)wireFrame +
@@ -182,6 +183,7 @@ int main(void)
CHECK(timing.captureTime == wireFrame->captureTime);
CHECK(timing.postProcessTime == wireFrame->postProcessTime);
CHECK(timing.copyTime == wireFrame->copyTime);
CHECK(timing.readyTime == wireFrame->readyTime);
LGT_LGMP.releaseFrame(transport, &frame);
CHECK(LGT_LGMP.nextPointer(transport, &pointer) == LG_TRANSPORT_OK);
LGT_LGMP.releasePointer(transport, &pointer);

View File

@@ -637,6 +637,7 @@ static void lgmp_getFrameTiming(LG_Transport * this,
timing->captureTime = this->pendingFrame->captureTime;
timing->postProcessTime = this->pendingFrame->postProcessTime;
timing->copyTime = this->pendingFrame->copyTime;
timing->readyTime = this->pendingFrame->readyTime;
}
static void lgmp_releaseFrame(LG_Transport * this, LG_TransportFrame * frame)

View File

@@ -30,7 +30,7 @@
#include "LGMPConfig.h"
#define KVMFR_MAGIC "KVMFR---"
#define KVMFR_VERSION 24
#define KVMFR_VERSION 25
// Fallback used by producers that cannot report the source display's SDR
// white level. IDD frames override this with IDDCX_METADATA2::SdrWhiteLevel.
@@ -201,12 +201,18 @@ typedef struct KVMFRFrame
uint64_t captureTime;
uint64_t postProcessTime;
uint64_t copyTime;
// Time from copy completion until FrameBuffer::wp publishes readiness.
uint64_t readyTime;
// Published after the timing fields and matched against frameSerial by the
// client. timingValid is written last by the producer.
uint32_t timingSerial;
uint32_t timingValid;
// Keep the conditional HDR block and damage rectangles on separate cache
// lines from the producer timing fields.
uint8_t timingReserved[24];
// HDR static metadata (valid when FRAME_FLAG_HDR_METADATA is set)
// Display color primaries in 0.00002 units (SMPTE ST 2086 format)
uint16_t hdrDisplayPrimary[3][2]; // Rx,Ry, Gx,Gy, Bx,By
@@ -220,6 +226,8 @@ typedef struct KVMFRFrame
uint32_t hdrMaxContentLightLevel; // MaxCLL (cd/m²)
uint32_t hdrMaxFrameAverageLightLevel; // MaxFALL (cd/m²)
uint8_t hdrReserved[32];
FrameDamageRect damageRects[KVMFR_MAX_DAMAGE_RECTS];
}
KVMFRFrame;
@@ -227,12 +235,16 @@ KVMFRFrame;
#if defined(__cplusplus)
static_assert(offsetof(KVMFRFrame, captureTime) == 64,
"KVMFRFrame hot fields must fit in one cache line");
static_assert(offsetof(KVMFRFrame, damageRects) == 128,
static_assert(offsetof(KVMFRFrame, hdrDisplayPrimary) == 128,
"KVMFRFrame HDR metadata must be cache-line aligned");
static_assert(offsetof(KVMFRFrame, damageRects) == 192,
"KVMFRFrame damage rectangles must be cache-line aligned");
#elif defined(__STDC_VERSION__) && __STDC_VERSION__ >= 201112L
_Static_assert(offsetof(KVMFRFrame, captureTime) == 64,
"KVMFRFrame hot fields must fit in one cache line");
_Static_assert(offsetof(KVMFRFrame, damageRects) == 128,
_Static_assert(offsetof(KVMFRFrame, hdrDisplayPrimary) == 128,
"KVMFRFrame HDR metadata must be cache-line aligned");
_Static_assert(offsetof(KVMFRFrame, damageRects) == 192,
"KVMFRFrame damage rectangles must be cache-line aligned");
#endif

View File

@@ -103,6 +103,9 @@ typedef struct CaptureFrame
uint64_t captureTime;
uint64_t postProcessTime;
uint64_t copyTime;
uint64_t readyTime;
// True when Copy is an explicit stage rather than the getFrame residual.
bool copyTimingValid;
}
CaptureFrame;

View File

@@ -194,7 +194,7 @@ static bool d12_copyTimingInit(
static void d12_copyTimingDeinit(void);
static void d12_copyTimingUpdateCalibration(void);
static bool d12_copyTimingGetStart(uint64_t * start);
static bool d12_copyTimingGetTimes(uint64_t * start, uint64_t * end);
// implementation
@@ -241,7 +241,7 @@ static bool d12_copyTimingInit(
D3D12_QUERY_HEAP_DESC queryDesc =
{
.Type = D3D12_QUERY_HEAP_TYPE_COPY_QUEUE_TIMESTAMP,
.Count = 1
.Count = 2
};
comRef_defineLocal(ID3D12QueryHeap, heap);
@@ -262,7 +262,7 @@ static bool d12_copyTimingInit(
D3D12_RESOURCE_DESC resourceDesc =
{
.Dimension = D3D12_RESOURCE_DIMENSION_BUFFER,
.Width = sizeof(UINT64),
.Width = sizeof(UINT64) * 2,
.Height = 1,
.DepthOrArraySize = 1,
.MipLevels = 1,
@@ -285,7 +285,7 @@ static bool d12_copyTimingInit(
if (FAILED(hr))
goto exit;
D3D12_RANGE readRange = {0, sizeof(UINT64)};
D3D12_RANGE readRange = {0, sizeof(UINT64) * 2};
void * timestampMap = NULL;
hr = ID3D12Resource_Map(*readback, 0, &readRange, &timestampMap);
if (FAILED(hr))
@@ -340,41 +340,47 @@ static void d12_copyTimingUpdateCalibration(void)
}
}
static bool d12_copyTimingGetStart(uint64_t * start)
static bool d12_copyTimingConvert(UINT64 gpuTime, uint64_t * cpuTime)
{
if (!this->copyTiming.supported)
return false;
const UINT64 gpuStart = *this->copyTiming.map;
UINT64 cpuStart;
if (gpuStart < this->copyTiming.calibrationGPU)
UINT64 qpcTime;
if (gpuTime < this->copyTiming.calibrationGPU)
{
const UINT64 delta = d12_scaleTicks(
this->copyTiming.calibrationGPU - gpuStart,
this->copyTiming.calibrationGPU - gpuTime,
this->copyTiming.qpcFrequency,
this->copyTiming.timestampFrequency);
if (delta > this->copyTiming.calibrationCPU)
return false;
cpuStart = this->copyTiming.calibrationCPU - delta;
qpcTime = this->copyTiming.calibrationCPU - delta;
}
else
{
const UINT64 delta = d12_scaleTicks(
gpuStart - this->copyTiming.calibrationGPU,
gpuTime - this->copyTiming.calibrationGPU,
this->copyTiming.qpcFrequency,
this->copyTiming.timestampFrequency);
if (UINT64_MAX - this->copyTiming.calibrationCPU < delta)
return false;
cpuStart = this->copyTiming.calibrationCPU + delta;
qpcTime = this->copyTiming.calibrationCPU + delta;
}
*start = d12_scaleTicks(
cpuStart, 1000000000ULL, this->copyTiming.qpcFrequency);
*cpuTime = d12_scaleTicks(
qpcTime, 1000000000ULL, this->copyTiming.qpcFrequency);
return true;
}
static bool d12_copyTimingGetTimes(uint64_t * start, uint64_t * end)
{
if (!this->copyTiming.supported ||
this->copyTiming.map[1] < this->copyTiming.map[0])
return false;
return d12_copyTimingConvert(this->copyTiming.map[0], start) &&
d12_copyTimingConvert(this->copyTiming.map[1], end);
}
static void d12_initOptions(void)
{
struct Option options[] =
@@ -980,6 +986,10 @@ static CaptureResult d12_getFrame(
CaptureFrame * captureFrame)
{
const uint64_t postProcessStart = nanotime();
captureFrame->postProcessTime = 0;
captureFrame->copyTime = 0;
captureFrame->readyTime = 0;
captureFrame->copyTimingValid = false;
CaptureResult result = CAPTURE_RESULT_ERROR;
comRef_scopePush(3);
@@ -1139,14 +1149,22 @@ static CaptureResult d12_getFrame(
}
if (this->copyTiming.supported)
{
ID3D12GraphicsCommandList_EndQuery(
*this->copyCommand.gfxList,
*this->copyTiming.heap,
D3D12_QUERY_TYPE_TIMESTAMP,
1);
ID3D12GraphicsCommandList_ResolveQueryData(
*this->copyCommand.gfxList,
*this->copyTiming.heap,
D3D12_QUERY_TYPE_TIMESTAMP,
0,
1,
2,
*this->copyTiming.readback,
0);
}
// execute the compute commands
if (this->effectsActive)
@@ -1172,13 +1190,21 @@ static CaptureResult d12_getFrame(
const uint64_t copyComplete = nanotime();
uint64_t copyStart;
if (!d12_copyTimingGetStart(&copyStart) ||
copyStart < postProcessStart || copyStart > copyComplete)
copyStart = fallbackCopyStart;
// The caller derives Copy from its getFrame wall time minus Post, preserving
// the exact producer total while moving the real queue wait to Post.
uint64_t copyEnd = 0;
if (d12_copyTimingGetTimes(&copyStart, &copyEnd) &&
copyStart >= postProcessStart && copyStart <= copyEnd &&
copyEnd <= copyComplete)
{
captureFrame->postProcessTime = copyStart - postProcessStart;
captureFrame->copyTime = copyEnd - copyStart;
captureFrame->copyTimingValid = true;
}
else
{
// Preserve the legacy attribution when copy-queue timestamps are not
// available or cannot be correlated safely with the producer clock.
captureFrame->postProcessTime = fallbackCopyStart - postProcessStart;
}
if (this->indirectCopy)
{
@@ -1205,6 +1231,10 @@ static CaptureResult d12_getFrame(
this->dstFormat.desc.Height * this->pitch);
}
const uint64_t readyEnd = nanotime();
if (captureFrame->copyTimingValid)
captureFrame->readyTime = readyEnd - copyEnd;
// reset the command queues
if (this->effectsActive)
{

View File

@@ -401,6 +401,7 @@ static bool sendFrame(CaptureResult result, bool * restart)
fi->captureTime = frame.captureTime;
fi->postProcessTime = 0;
fi->copyTime = 0;
fi->readyTime = 0;
fi->timingSerial = 0;
__atomic_store_n(&fi->timingValid, 0, __ATOMIC_RELAXED);
if (frame.hdrMetadata)
@@ -449,9 +450,19 @@ static bool sendFrame(CaptureResult result, bool * restart)
const uint64_t copyEnd = nanotime();
fi->postProcessTime = frame.postProcessTime;
frame.copyTime = copyEnd - copyStart > frame.postProcessTime ?
copyEnd - copyStart - frame.postProcessTime : 0;
const uint64_t totalTime = copyEnd - copyStart;
const bool splitTimingValid = frame.copyTimingValid &&
frame.postProcessTime <= totalTime &&
frame.copyTime <= totalTime - frame.postProcessTime &&
frame.readyTime <= totalTime - frame.postProcessTime - frame.copyTime;
if (!splitTimingValid)
{
frame.copyTime = totalTime > frame.postProcessTime ?
totalTime - frame.postProcessTime : 0;
frame.readyTime = 0;
}
fi->copyTime = frame.copyTime;
fi->readyTime = frame.readyTime;
fi->timingSerial = fi->frameSerial;
__atomic_store_n(&fi->timingValid, 1, __ATOMIC_RELEASE);

View File

@@ -56,7 +56,7 @@ bool CD3D12CommandQueue::InitTiming(ID3D12Device3 * device,
D3D12_QUERY_HEAP_DESC queryDesc = {};
queryDesc.Type = D3D12_QUERY_HEAP_TYPE_COPY_QUEUE_TIMESTAMP;
queryDesc.Count = 1;
queryDesc.Count = 2;
hr = device->CreateQueryHeap(&queryDesc, IID_PPV_ARGS(&m_timestampHeap));
if (FAILED(hr))
@@ -71,7 +71,7 @@ bool CD3D12CommandQueue::InitTiming(ID3D12Device3 * device,
D3D12_RESOURCE_DESC resourceDesc = {};
resourceDesc.Dimension = D3D12_RESOURCE_DIMENSION_BUFFER;
resourceDesc.Width = sizeof(UINT64);
resourceDesc.Width = sizeof(UINT64) * 2;
resourceDesc.Height = 1;
resourceDesc.DepthOrArraySize = 1;
resourceDesc.MipLevels = 1;
@@ -91,7 +91,7 @@ bool CD3D12CommandQueue::InitTiming(ID3D12Device3 * device,
return false;
}
D3D12_RANGE readRange = { 0, sizeof(UINT64) };
D3D12_RANGE readRange = { 0, sizeof(UINT64) * 2 };
void * timestampMap = nullptr;
hr = m_timestampReadback->Map(0, &readRange, &timestampMap);
if (FAILED(hr))
@@ -298,37 +298,47 @@ void CD3D12CommandQueue::EndTiming()
if (!m_timingActive)
return;
m_gfxList->EndQuery(
m_timestampHeap.Get(), D3D12_QUERY_TYPE_TIMESTAMP, 1);
m_gfxList->ResolveQueryData(
m_timestampHeap.Get(), D3D12_QUERY_TYPE_TIMESTAMP,
0, 1, m_timestampReadback.Get(), 0);
0, 2, m_timestampReadback.Get(), 0);
}
bool CD3D12CommandQueue::GetGPUStartTime(uint64_t& start)
bool CD3D12CommandQueue::ConvertGPUTimestamp(
UINT64 timestamp, uint64_t& result) const
{
if (!m_timingActive)
return false;
const UINT64 gpuStart = m_timestampMap[0];
UINT64 cpuStart;
if (gpuStart < m_calibrationGPU)
UINT64 cpuTimestamp;
if (timestamp < m_calibrationGPU)
{
const UINT64 delta = ScaleTicks(
m_calibrationGPU - gpuStart, m_qpcFrequency, m_timestampFrequency);
m_calibrationGPU - timestamp, m_qpcFrequency, m_timestampFrequency);
if (delta > m_calibrationCPU)
return false;
cpuStart = m_calibrationCPU - delta;
cpuTimestamp = m_calibrationCPU - delta;
}
else
{
const UINT64 delta = ScaleTicks(
gpuStart - m_calibrationGPU, m_qpcFrequency, m_timestampFrequency);
timestamp - m_calibrationGPU, m_qpcFrequency, m_timestampFrequency);
if (UINT64_MAX - m_calibrationCPU < delta)
return false;
cpuStart = m_calibrationCPU + delta;
cpuTimestamp = m_calibrationCPU + delta;
}
start = TicksToNanoseconds(cpuStart, m_qpcFrequency);
result = TicksToNanoseconds(cpuTimestamp, m_qpcFrequency);
return true;
}
bool CD3D12CommandQueue::GetGPUTimes(
uint64_t& start, uint64_t& end) const
{
if (!m_timingActive ||
!ConvertGPUTimestamp(m_timestampMap[0], start) ||
!ConvertGPUTimestamp(m_timestampMap[1], end) ||
end < start)
return false;
return true;
}

View File

@@ -67,6 +67,7 @@ class CD3D12CommandQueue
bool InitTiming(ID3D12Device3 * device, D3D12_COMMAND_LIST_TYPE type);
void UpdateClockCalibration();
bool ConvertGPUTimestamp(UINT64 timestamp, uint64_t& result) const;
void OnCompletion()
{
@@ -108,8 +109,8 @@ class CD3D12CommandQueue
bool BeginTiming();
void EndTiming();
// Return the command-list start in QueryPerformanceCounter-domain ns.
bool GetGPUStartTime(uint64_t& start);
// Return the copy boundaries in QueryPerformanceCounter-domain ns.
bool GetGPUTimes(uint64_t& start, uint64_t& end) const;
//void Wait();
bool IsReady () const { return !m_pending ; }

View File

@@ -1302,6 +1302,7 @@ CIndirectDeviceContext::PreparedFrameBuffer CIndirectDeviceContext::PrepareFrame
fi->captureTime = 0;
fi->postProcessTime = 0;
fi->copyTime = 0;
fi->readyTime = 0;
fi->timingSerial = 0;
InterlockedExchange((volatile LONG *)&fi->timingValid, 0);
fi->rotation = FRAME_ROT_0;
@@ -1370,7 +1371,8 @@ bool CIndirectDeviceContext::PublishFrameBuffer(unsigned frameIndex)
}
void CIndirectDeviceContext::SetFrameTiming(unsigned frameIndex,
uint64_t captureTime, uint64_t postProcessTime, uint64_t copyTime)
uint64_t captureTime, uint64_t postProcessTime, uint64_t copyTime,
uint64_t readyTime)
{
if (frameIndex >= LGMP_Q_FRAME_LEN)
return;
@@ -1379,6 +1381,7 @@ void CIndirectDeviceContext::SetFrameTiming(unsigned frameIndex,
frame->captureTime = captureTime;
frame->postProcessTime = postProcessTime;
frame->copyTime = copyTime;
frame->readyTime = readyTime;
frame->timingSerial = frame->frameSerial;
InterlockedExchange((volatile LONG *)&frame->timingValid, 1);
}

View File

@@ -218,7 +218,7 @@ public:
PreparedFrameBuffer PrepareFrameBuffer(unsigned pitch, const D12FrameFormat& srcFormat, const D12FrameFormat& dstFormat, const RECT * dirtyRects, unsigned nbDirtyRects);
bool PublishFrameBuffer(unsigned frameIndex);
void SetFrameTiming(unsigned frameIndex, uint64_t captureTime,
uint64_t postProcessTime, uint64_t copyTime);
uint64_t postProcessTime, uint64_t copyTime, uint64_t readyTime);
void WriteFrameBuffer(unsigned frameIndex, void* src, size_t offset, size_t len, bool setWritePos) const;
void FinalizeFrameBuffer(unsigned frameIndex) const;

View File

@@ -318,32 +318,38 @@ void CSwapChainProcessor::CompletionFunction(
auto sc = (CSwapChainProcessor *)param1;
auto fbRes = (CFrameBufferResource *)param2;
uint64_t copyStart = fbRes->GetCopyStart();
const uint64_t cpuCopyStart = fbRes->GetCopyStart();
uint64_t gpuCopyStart = 0;
uint64_t gpuCopyEnd = 0;
if (result && sc->m_dx12Device->IsIndirectCopy())
sc->m_devContext->WriteFrameBuffer(
fbRes->GetFrameIndex(), fbRes->GetMap(), 0, fbRes->GetFrameSize(), false);
// Queue waits execute before this timestamp. Use it as the boundary so the
// source fence and effects are charged to Post, while Copy retains the full
// time through buffer readiness and any indirect memcpy.
const bool gpuTimingValid = result && queue->GetGPUStartTime(gpuCopyStart);
// Queue waits execute before the start timestamp. The end timestamp follows
// the last CopyTextureRegion, separating GPU work from readiness dispatch.
const bool gpuTimingValid = result &&
queue->GetGPUTimes(gpuCopyStart, gpuCopyEnd);
// Publish readiness before sampling the endpoint. Timing has its own valid
// flag and is published immediately afterwards.
sc->m_devContext->FinalizeFrameBuffer(fbRes->GetFrameIndex());
const uint64_t copyEnd = Nanotime();
const uint64_t readyEnd = Nanotime();
uint64_t postProcessTime = cpuCopyStart - fbRes->GetPostProcessStart();
uint64_t copyTime = readyEnd - cpuCopyStart;
uint64_t readyTime = 0;
if (gpuTimingValid &&
gpuCopyStart >= fbRes->GetPostProcessStart() &&
gpuCopyStart <= copyEnd)
copyStart = gpuCopyStart;
gpuCopyEnd <= readyEnd)
{
postProcessTime = gpuCopyStart - fbRes->GetPostProcessStart();
copyTime = gpuCopyEnd - gpuCopyStart;
readyTime = readyEnd - gpuCopyEnd;
}
const uint64_t postProcessTime = copyStart -
fbRes->GetPostProcessStart();
const uint64_t copyTime = copyEnd - copyStart;
sc->m_devContext->SetFrameTiming(fbRes->GetFrameIndex(),
fbRes->GetCaptureTime(), postProcessTime, copyTime);
fbRes->GetCaptureTime(), postProcessTime, copyTime, readyTime);
}