From 7533c855c27daa965155c1d54a83200fdca4920b Mon Sep 17 00:00:00 2001 From: Geoffrey McRae Date: Mon, 3 Aug 2026 10:57:32 +1000 Subject: [PATCH] [client/host/idd/lgmp] add additional timing metrics --- client/include/interface/transport.h | 13 ++++ client/src/main.c | 63 +++++++++++++++---- client/src/main.h | 5 ++ client/tests/lgmp_transport_test.c | 35 +++++++---- client/transports/LGMP/lgmp.c | 36 +++++++++++ common/include/common/KVMFR.h | 47 ++++++++++++-- host/include/interface/capture.h | 11 +++- host/platform/Linux/capture/XCB/src/xcb.c | 6 +- .../Linux/capture/pipewire/src/pipewire.c | 6 +- host/platform/Windows/capture/D12/d12.c | 11 +++- host/platform/Windows/capture/DXGI/src/dxgi.c | 8 ++- .../Windows/capture/NVFBC/src/nvfbc.c | 8 ++- host/src/app.c | 25 +++++++- idd/LGIdd/CFrameBufferResource.h | 26 ++++++-- idd/LGIdd/CIndirectDeviceContext.cpp | 49 ++++++++++----- idd/LGIdd/CIndirectDeviceContext.h | 33 +++++----- idd/LGIdd/CSwapChainProcessor.cpp | 43 ++++++++++--- idd/LGIdd/CSwapChainProcessor.h | 2 +- 18 files changed, 339 insertions(+), 88 deletions(-) diff --git a/client/include/interface/transport.h b/client/include/interface/transport.h index bcf0c6a2..04e17ad5 100644 --- a/client/include/interface/transport.h +++ b/client/include/interface/transport.h @@ -92,6 +92,14 @@ enum typedef uint32_t LG_TransportFrameFlags; +typedef struct LG_TransportFrameTiming +{ + uint64_t captureTime; + uint64_t postProcessTime; + uint64_t copyTime; +} +LG_TransportFrameTiming; + typedef struct LG_TransportFrameFormat { uint32_t version; @@ -200,6 +208,11 @@ typedef struct LG_TransportOps LG_TransportStatus (*nextFrame)(LG_Transport * transport, bool useDMA, LG_TransportFrame * frame); + /* Read producer timings after the renderer has consumed the frame. Some + * transports publish the frame while its asynchronous copy is in progress, + * so these values are intentionally sampled late. */ + void (*getFrameTiming)(LG_Transport * transport, + const LG_TransportFrame * frame, LG_TransportFrameTiming * timing); void (*releaseFrame)(LG_Transport * transport, LG_TransportFrame * frame); /* Called by the frame consumer as it exits. A backend may release transient * stream resources; nextFrame must reacquire them when the consumer restarts. */ diff --git a/client/src/main.c b/client/src/main.c index 57fb610c..038ca81b 100644 --- a/client/src/main.c +++ b/client/src/main.c @@ -199,11 +199,21 @@ static bool tickTimerFn(void * unused) return true; } +struct RenderTiming +{ + uint64_t renderStart; + uint64_t producerTime; +}; + static void preSwapCallback(void * udata) { - const uint64_t * renderStart = (const uint64_t *)udata; - ringbuffer_push(g_state.renderDuration, - &(float) {(nanotime() - *renderStart) * 1e-6f}); + const struct RenderTiming * timing = (const struct RenderTiming *)udata; + const uint64_t renderTime = nanotime() - timing->renderStart; + ringbuffer_push(g_state.renderDuration, &(float) {renderTime * 1e-6f}); + + if (timing->producerTime) + ringbuffer_push(g_state.endToEndDuration, + &(float) {(timing->producerTime + renderTime) * 1e-6f}); #ifdef ENABLE_TESTS if (!l_testCapture.enabled || l_testCapture.complete) @@ -397,13 +407,17 @@ static int renderThread(void * unused) const bool invalidate = atomic_exchange(&g_state.invalidateWindow, false); - const uint64_t renderStart = nanotime(); + const struct RenderTiming renderTiming = { + .renderStart = nanotime(), + .producerTime = newFrame ? atomic_load_explicit( + &g_state.producerFrameTime, memory_order_acquire) : 0, + }; LG_LOCK(g_state.lgrLock); renderQueue_process(); if (unlikely(!RENDERER(render, g_params.winRotate, newFrame, invalidate, - preSwapCallback, (void *)&renderStart))) + preSwapCallback, (void *)&renderTiming))) { LG_UNLOCK(g_state.lgrLock); break; @@ -778,6 +792,21 @@ int main_frameThread(void * unused) break; } + LG_TransportFrameTiming timing = {}; + if (g_state.transportOps->getFrameTiming) + g_state.transportOps->getFrameTiming( + g_state.transport, &frame, &timing); + + ringbuffer_push(g_state.captureDuration, + &(float) {timing.captureTime * 1e-6f}); + ringbuffer_push(g_state.postProcessDuration, + &(float) {timing.postProcessTime * 1e-6f}); + ringbuffer_push(g_state.copyDuration, + &(float) {timing.copyTime * 1e-6f}); + atomic_store_explicit(&g_state.producerFrameTime, + timing.captureTime + timing.postProcessTime + timing.copyTime, + memory_order_release); + overlaySplash_show(false); if ((frame.flags & LG_TRANSPORT_FRAME_REQUEST_ACTIVATION) && g_params.requestActivation) @@ -1305,12 +1334,20 @@ static int lg_run(void) DEBUG_INFO("Using font: %s", g_state.fontName); // initialize metrics ringbuffers - g_state.renderTimings = ringbuffer_new(256, sizeof(float)); - g_state.uploadTimings = ringbuffer_new(256, sizeof(float)); - g_state.renderDuration = ringbuffer_new(256, sizeof(float)); - overlayGraph_register("FRAME" , g_state.renderTimings , 0.0f, 50.0f, NULL); - overlayGraph_register("UPLOAD", g_state.uploadTimings , 0.0f, 50.0f, NULL); - overlayGraph_register("RENDER", g_state.renderDuration, 0.0f, 10.0f, NULL); + g_state.renderTimings = ringbuffer_new(256, sizeof(float)); + g_state.uploadTimings = ringbuffer_new(256, sizeof(float)); + g_state.renderDuration = ringbuffer_new(256, sizeof(float)); + g_state.captureDuration = ringbuffer_new(256, sizeof(float)); + g_state.postProcessDuration = ringbuffer_new(256, sizeof(float)); + g_state.copyDuration = ringbuffer_new(256, sizeof(float)); + g_state.endToEndDuration = ringbuffer_new(256, sizeof(float)); + overlayGraph_register("FRAME" , g_state.renderTimings , 0.0f, 50.0f, NULL); + overlayGraph_register("UPLOAD" , g_state.uploadTimings , 0.0f, 50.0f, NULL); + overlayGraph_register("RENDER" , g_state.renderDuration , 0.0f, 10.0f, NULL); + overlayGraph_register("CAPTURE" , g_state.captureDuration , 0.0f, 20.0f, NULL); + overlayGraph_register("POST PROCESS", g_state.postProcessDuration, 0.0f, 20.0f, NULL); + overlayGraph_register("COPY" , g_state.copyDuration , 0.0f, 20.0f, NULL); + overlayGraph_register("END TO END" , g_state.endToEndDuration , 0.0f, 50.0f, NULL); // unknown guest OS at this time g_state.guestOS = LG_TRANSPORT_OS_OTHER; @@ -1795,6 +1832,10 @@ static void lg_shutdown(void) ringbuffer_free(&g_state.renderTimings); ringbuffer_free(&g_state.uploadTimings); ringbuffer_free(&g_state.renderDuration); + ringbuffer_free(&g_state.captureDuration); + ringbuffer_free(&g_state.postProcessDuration); + ringbuffer_free(&g_state.copyDuration); + ringbuffer_free(&g_state.endToEndDuration); free(g_state.fontName); igDestroyContext(NULL); diff --git a/client/src/main.h b/client/src/main.h index df2e698b..0dd690ca 100644 --- a/client/src/main.h +++ b/client/src/main.h @@ -150,8 +150,13 @@ struct AppState RingBuffer renderTimings; RingBuffer renderDuration; RingBuffer uploadTimings; + RingBuffer captureDuration; + RingBuffer postProcessDuration; + RingBuffer copyDuration; + RingBuffer endToEndDuration; atomic_uint_least64_t pendingCount; + atomic_uint_least64_t producerFrameTime; atomic_uint_least64_t renderCount, frameCount; _Atomic(float) fps, ups; diff --git a/client/tests/lgmp_transport_test.c b/client/tests/lgmp_transport_test.c index 3d6a1342..53fd149c 100644 --- a/client/tests/lgmp_transport_test.c +++ b/client/tests/lgmp_transport_test.c @@ -122,17 +122,22 @@ int main(void) wireFrame->formatVer = 1; wireFrame->frameSerial = 1; wireFrame->type = FRAME_TYPE_BGRA; - wireFrame->screenWidth = 1; - wireFrame->screenHeight = 1; - wireFrame->dataWidth = 1; - wireFrame->dataHeight = 1; - wireFrame->frameWidth = 1; - wireFrame->frameHeight = 1; - wireFrame->rotation = FRAME_ROT_0; - wireFrame->stride = 1; - wireFrame->pitch = sizeof(uint32_t); - wireFrame->offset = sizeof(*wireFrame); - wireFrame->sdrWhiteLevel = KVMFR_SDR_WHITE_LEVEL_DEFAULT; + wireFrame->screenWidth = 1; + wireFrame->screenHeight = 1; + wireFrame->dataWidth = 1; + wireFrame->dataHeight = 1; + wireFrame->frameWidth = 1; + wireFrame->frameHeight = 1; + wireFrame->rotation = FRAME_ROT_0; + wireFrame->stride = 1; + wireFrame->pitch = sizeof(uint32_t); + wireFrame->offset = sizeof(*wireFrame); + wireFrame->sdrWhiteLevel = KVMFR_SDR_WHITE_LEVEL_DEFAULT; + wireFrame->captureTime = 100; + wireFrame->postProcessTime = 200; + wireFrame->copyTime = 300; + wireFrame->timingSerial = wireFrame->frameSerial; + wireFrame->timingValid = 1; FrameBuffer * framebuffer = (FrameBuffer *)((uint8_t *)wireFrame + wireFrame->offset); atomic_store(&framebuffer->wp, sizeof(uint32_t)); @@ -172,6 +177,11 @@ int main(void) CHECK(lgmpHostQueuePost(pointerQueue, CURSOR_FLAG_POSITION, pointerMemory) == LGMP_OK); CHECK(LGT_LGMP.nextFrame(transport, false, &frame) == LG_TRANSPORT_OK); + LG_TransportFrameTiming timing; + LGT_LGMP.getFrameTiming(transport, &frame, &timing); + CHECK(timing.captureTime == wireFrame->captureTime); + CHECK(timing.postProcessTime == wireFrame->postProcessTime); + CHECK(timing.copyTime == wireFrame->copyTime); LGT_LGMP.releaseFrame(transport, &frame); CHECK(LGT_LGMP.nextPointer(transport, &pointer) == LG_TRANSPORT_OK); LGT_LGMP.releasePointer(transport, &pointer); @@ -212,7 +222,8 @@ int main(void) * Also recover when the host has already marked the cached handles bad. * LGMP leaves a timed-out handle non-NULL when unsubscribe fails. */ - wireFrame->frameSerial = 2; + wireFrame->frameSerial = 2; + wireFrame->timingSerial = wireFrame->frameSerial; CHECK(lgmpHostQueuePost(frameQueue, 0, frameMemory) == LGMP_OK); CHECK(lgmpHostQueuePost(pointerQueue, CURSOR_FLAG_POSITION, pointerMemory) == LGMP_OK); diff --git a/client/transports/LGMP/lgmp.c b/client/transports/LGMP/lgmp.c index 1a6dc303..434d3dd9 100644 --- a/client/transports/LGMP/lgmp.c +++ b/client/transports/LGMP/lgmp.c @@ -56,6 +56,7 @@ struct LG_Transport bool allowDMA; bool connected; bool framePending; + const KVMFRFrame * pendingFrame; uint32_t frameSerial; bool formatValid; LG_TransportFrameFormat format; @@ -214,6 +215,7 @@ static void lgmp_stopFrame(struct LG_Transport * this) lgmpStatusString(status)); } this->framePending = false; + this->pendingFrame = NULL; LGMP_STATUS status = lgmpClientUnsubscribe(&this->frameQueue); if (status != LGMP_OK) { @@ -602,14 +604,47 @@ static LG_TransportStatus lgmp_nextFrame(LG_Transport * this, bool useDMA, DEBUG_WARN("Invalid damage rectangles, forcing a full update"); this->framePending = true; + this->pendingFrame = frame; return LG_TRANSPORT_OK; } +static bool lgmp_frameTimingReady(const KVMFRFrame * frame) +{ + return __atomic_load_n(&frame->timingValid, __ATOMIC_ACQUIRE) && + frame->timingSerial == frame->frameSerial; +} + +static void lgmp_getFrameTiming(LG_Transport * this, + const LG_TransportFrame * frame, LG_TransportFrameTiming * timing) +{ + memset(timing, 0, sizeof(*timing)); + if (!this->framePending || !this->pendingFrame || + this->pendingFrame->frameSerial != frame->serial) + return; + + /* The producer writes these immediately before completing the framebuffer. + * nextFrame can observe the header earlier, so sample them only after the + * renderer's onFrame call has consumed the framebuffer. */ + for (unsigned i = 0; + !lgmp_frameTimingReady(this->pendingFrame) && + i < 1000; + ++i) + usleep(1); + + if (!lgmp_frameTimingReady(this->pendingFrame)) + return; + + timing->captureTime = this->pendingFrame->captureTime; + timing->postProcessTime = this->pendingFrame->postProcessTime; + timing->copyTime = this->pendingFrame->copyTime; +} + static void lgmp_releaseFrame(LG_Transport * this, LG_TransportFrame * frame) { if (this->framePending && this->frameQueue) lgmpClientMessageDone(this->frameQueue); this->framePending = false; + this->pendingFrame = NULL; memset(frame, 0, sizeof(*frame)); } @@ -800,6 +835,7 @@ const LG_TransportOps LGT_LGMP = .attachRenderer = lgmp_attachRenderer, .detachRenderer = lgmp_detachRenderer, .nextFrame = lgmp_nextFrame, + .getFrameTiming = lgmp_getFrameTiming, .releaseFrame = lgmp_releaseFrame, .stopFrame = lgmp_stopFrame, .nextPointer = lgmp_nextPointer, diff --git a/common/include/common/KVMFR.h b/common/include/common/KVMFR.h index 3e485484..7ad0c7d4 100644 --- a/common/include/common/KVMFR.h +++ b/common/include/common/KVMFR.h @@ -25,11 +25,12 @@ #include #include +#include #include "types.h" #include "LGMPConfig.h" #define KVMFR_MAGIC "KVMFR---" -#define KVMFR_VERSION 23 +#define KVMFR_VERSION 24 // Fallback used by producers that cannot report the source display's SDR // white level. IDD frames override this with IDDCX_METADATA2::SdrWhiteLevel. @@ -165,6 +166,11 @@ typedef uint32_t KVMFRFrameFlags; typedef struct KVMFRFrame { + /* + * Keep the fields consumed for every frame in the first cache line. The + * timing and HDR metadata below are diagnostic/conditional, while the large + * damage rectangle array is deliberately last. + */ uint32_t formatVer; // the frame format version number uint32_t frameSerial; // the unique frame number FrameType type; // the frame data type @@ -178,9 +184,28 @@ typedef struct KVMFRFrame uint32_t stride; // the row stride (zero if compressed data) uint32_t pitch; // the row pitch (stride in bytes or the compressed frame size) uint32_t offset; // offset from the start of this header to the FrameBuffer header - uint32_t damageRectsCount; // the number of damage rectangles (zero for full-frame damage) - FrameDamageRect damageRects[KVMFR_MAX_DAMAGE_RECTS]; KVMFRFrameFlags flags; // bit field combination of FRAME_FLAG_* + uint32_t damageRectsCount; // the number of damage rectangles (zero for full-frame damage) + + // White level in nits for SDR content composited into an HDR frame, such as + // the hardware cursor. Valid for all frames; SDR modes normally report 80. + uint32_t sdrWhiteLevel; + + /* + * Producer stage durations in nanoseconds. These are durations rather than + * absolute timestamps because the producer runs in a VM whose monotonic + * clock has a different epoch from the client. Durations can safely be + * combined with the client's local render duration for an end-to-end + * processing time. + */ + uint64_t captureTime; + uint64_t postProcessTime; + uint64_t copyTime; + + // 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; // HDR static metadata (valid when FRAME_FLAG_HDR_METADATA is set) // Display color primaries in 0.00002 units (SMPTE ST 2086 format) @@ -195,12 +220,22 @@ typedef struct KVMFRFrame uint32_t hdrMaxContentLightLevel; // MaxCLL (cd/m²) uint32_t hdrMaxFrameAverageLightLevel; // MaxFALL (cd/m²) - // White level in nits for SDR content composited into an HDR frame, such as - // the hardware cursor. Valid for all frames; SDR modes normally report 80. - uint32_t sdrWhiteLevel; + FrameDamageRect damageRects[KVMFR_MAX_DAMAGE_RECTS]; } 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, + "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, + "KVMFRFrame damage rectangles must be cache-line aligned"); +#endif + typedef struct KVMFRMessage { KVMFRMessageType type; diff --git a/host/include/interface/capture.h b/host/include/interface/capture.h index 5040f133..8c7eb046 100644 --- a/host/include/interface/capture.h +++ b/host/include/interface/capture.h @@ -97,6 +97,12 @@ typedef struct CaptureFrame uint32_t damageRectsCount; FrameDamageRect damageRects[KVMFR_MAX_DAMAGE_RECTS]; + + // Producer-local durations. Absolute timestamps must not cross KVMFR as the + // client and producer use different monotonic clock domains. + uint64_t captureTime; + uint64_t postProcessTime; + uint64_t copyTime; } CaptureFrame; @@ -146,8 +152,9 @@ typedef struct CaptureInterface CaptureFrame * frame, const size_t maxFrameSize); CaptureResult (*getFrame )( - unsigned frameBufferIndex, + unsigned frameBufferIndex, FrameBuffer * frame, - const size_t maxFrameSize); + const size_t maxFrameSize, + CaptureFrame * captureFrame); } CaptureInterface; diff --git a/host/platform/Linux/capture/XCB/src/xcb.c b/host/platform/Linux/capture/XCB/src/xcb.c index 744d6eaf..c5e94408 100644 --- a/host/platform/Linux/capture/XCB/src/xcb.c +++ b/host/platform/Linux/capture/XCB/src/xcb.c @@ -299,10 +299,12 @@ static CaptureResult xcb_waitFrame( } static CaptureResult xcb_getFrame( - unsigned frameBufferIndex, + unsigned frameBufferIndex, FrameBuffer * frame, - const size_t maxFrameSize) + const size_t maxFrameSize, + CaptureFrame * captureFrame) { + (void)captureFrame; DEBUG_ASSERT(this); DEBUG_ASSERT(this->initialized); diff --git a/host/platform/Linux/capture/pipewire/src/pipewire.c b/host/platform/Linux/capture/pipewire/src/pipewire.c index de0211de..bca94b30 100644 --- a/host/platform/Linux/capture/pipewire/src/pipewire.c +++ b/host/platform/Linux/capture/pipewire/src/pipewire.c @@ -463,10 +463,12 @@ static CaptureResult pipewire_waitFrame( } static CaptureResult pipewire_getFrame( - unsigned frameBufferIndex, + unsigned frameBufferIndex, FrameBuffer * frame, - const size_t maxFrameSize) + const size_t maxFrameSize, + CaptureFrame * captureFrame) { + (void)captureFrame; if (this->stop || !this->frameData) return CAPTURE_RESULT_REINIT; diff --git a/host/platform/Windows/capture/D12/d12.c b/host/platform/Windows/capture/D12/d12.c index 2cca61c7..33887280 100644 --- a/host/platform/Windows/capture/D12/d12.c +++ b/host/platform/Windows/capture/D12/d12.c @@ -29,6 +29,7 @@ #include "common/rects.h" #include "common/vector.h" #include "common/display.h" +#include "common/time.h" #include "com_ref.h" #include "backend.h" @@ -771,8 +772,11 @@ exit: return result; } -static CaptureResult d12_getFrame(unsigned frameBufferIndex, - FrameBuffer * frameBuffer, const size_t maxFrameSize) +static CaptureResult d12_getFrame( + unsigned frameBufferIndex, + FrameBuffer * frameBuffer, + const size_t maxFrameSize, + CaptureFrame * captureFrame) { CaptureResult result = CAPTURE_RESULT_ERROR; comRef_scopePush(3); @@ -808,6 +812,7 @@ static CaptureResult d12_getFrame(unsigned frameBufferIndex, if (result != CAPTURE_RESULT_OK) goto exit; + const uint64_t postProcessStart = nanotime(); ID3D12Resource * next = *src; D12Effect * effect; vector_forEach(effect, &this->effects) @@ -934,6 +939,8 @@ static CaptureResult d12_getFrame(unsigned frameBufferIndex, ID3D12CommandQueue_Wait(*this->copyQueue, *this->computeCommand.fence, this->computeCommand.fenceValue); } + captureFrame->postProcessTime = this->effectsActive ? + nanotime() - postProcessStart : 0; // execute the copy commands DEBUG_TRACE("Execute copy commands"); diff --git a/host/platform/Windows/capture/DXGI/src/dxgi.c b/host/platform/Windows/capture/DXGI/src/dxgi.c index b03f2992..35eff1fa 100644 --- a/host/platform/Windows/capture/DXGI/src/dxgi.c +++ b/host/platform/Windows/capture/DXGI/src/dxgi.c @@ -1504,9 +1504,13 @@ static CaptureResult dxgi_waitFrame(unsigned frameBufferIndex, return CAPTURE_RESULT_OK; } -static CaptureResult dxgi_getFrame(unsigned frameBufferIndex, - FrameBuffer * frame, const size_t maxFrameSize) +static CaptureResult dxgi_getFrame( + unsigned frameBufferIndex, + FrameBuffer * frame, + const size_t maxFrameSize, + CaptureFrame * captureFrame) { + (void)captureFrame; DEBUG_ASSERT(this); DEBUG_ASSERT(this->initialized); diff --git a/host/platform/Windows/capture/NVFBC/src/nvfbc.c b/host/platform/Windows/capture/NVFBC/src/nvfbc.c index b8aa4f9d..b6a74ba4 100644 --- a/host/platform/Windows/capture/NVFBC/src/nvfbc.c +++ b/host/platform/Windows/capture/NVFBC/src/nvfbc.c @@ -718,9 +718,13 @@ static CaptureResult nvfbc_waitFrame(unsigned frameBufferIndex, return CAPTURE_RESULT_OK; } -static CaptureResult nvfbc_getFrame(unsigned frameBufferIndex, - FrameBuffer * frame, const size_t maxFrameSize) +static CaptureResult nvfbc_getFrame( + unsigned frameBufferIndex, + FrameBuffer * frame, + const size_t maxFrameSize, + CaptureFrame * captureFrame) { + (void)captureFrame; const unsigned int h = DIFF_MAP_DIM(this->grabHeight, this->diffShift); const unsigned int w = DIFF_MAP_DIM(this->grabWidth, this->diffShift); uint8_t * frameData = framebuffer_get_data(frame); diff --git a/host/src/app.c b/host/src/app.c index ca4e4be2..9b1f3837 100644 --- a/host/src/app.c +++ b/host/src/app.c @@ -109,6 +109,7 @@ struct app bool frameValid; uint32_t frameSerial; uint32_t formatVer; + uint64_t captureTime[LGMP_Q_FRAME_LEN]; unsigned int captureFormatVer; bool hdr; bool hdrPQ; @@ -291,6 +292,7 @@ static bool sendFrame(CaptureResult result, bool * restart) } KVMFRFrame * fi = app.frame[app.captureIndex]; + frame.captureTime = app.captureTime[app.captureIndex]; const uint32_t sdrWhiteLevel = frame.sdrWhiteLevel ? frame.sdrWhiteLevel : KVMFR_SDR_WHITE_LEVEL_DEFAULT; const bool metadataChanged = @@ -396,6 +398,11 @@ static bool sendFrame(CaptureResult result, bool * restart) // fi->offset is initialized at startup fi->flags = flags; fi->sdrWhiteLevel = sdrWhiteLevel; + fi->captureTime = frame.captureTime; + fi->postProcessTime = 0; + fi->copyTime = 0; + fi->timingSerial = 0; + __atomic_store_n(&fi->timingValid, 0, __ATOMIC_RELAXED); if (frame.hdrMetadata) { memcpy(fi->hdrDisplayPrimary, frame.hdrDisplayPrimary, @@ -433,10 +440,20 @@ static bool sendFrame(CaptureResult result, bool * restart) return true; } + const uint64_t copyStart = nanotime(); app.iface->getFrame( app.captureIndex, app.frameBuffer[app.captureIndex], - app.maxFrameSize); + app.maxFrameSize, + &frame); + const uint64_t copyEnd = nanotime(); + + fi->postProcessTime = frame.postProcessTime; + frame.copyTime = copyEnd - copyStart > frame.postProcessTime ? + copyEnd - copyStart - frame.postProcessTime : 0; + fi->copyTime = frame.copyTime; + fi->timingSerial = fi->frameSerial; + __atomic_store_n(&fi->timingValid, 1, __ATOMIC_RELEASE); app.readIndex = app.captureIndex; if (++app.captureIndex == LGMP_Q_FRAME_LEN) @@ -1108,13 +1125,15 @@ int app_main(int argc, char * argv[]) nsleep(us * 1000); } - const uint64_t captureStartTime = microtime(); + const uint64_t captureStartTime = nanotime(); const CaptureResult result = app.iface->capture( app.captureIndex, app.frameBuffer[app.captureIndex]); + app.captureTime[app.captureIndex] = nanotime() - captureStartTime; + if (likely(result == CAPTURE_RESULT_OK)) - previousFrameTime = captureStartTime; + previousFrameTime = captureStartTime / 1000; else if (likely(result == CAPTURE_RESULT_TIMEOUT)) { if (!app.iface->asyncCapture) diff --git a/idd/LGIdd/CFrameBufferResource.h b/idd/LGIdd/CFrameBufferResource.h index 234c2ef3..118e57f0 100644 --- a/idd/LGIdd/CFrameBufferResource.h +++ b/idd/LGIdd/CFrameBufferResource.h @@ -33,13 +33,16 @@ using namespace Microsoft::WRL; class CFrameBufferResource { private: - bool m_valid = false; - unsigned m_frameIndex = 0; - uint8_t * m_base = nullptr; - size_t m_size = 0; - size_t m_frameSize = 0; + bool m_valid = false; + unsigned m_frameIndex = 0; + uint8_t * m_base = nullptr; + size_t m_size = 0; + size_t m_frameSize = 0; + uint64_t m_captureTime = 0; + uint64_t m_postProcessTime = 0; + uint64_t m_copyStart = 0; ComPtr m_res; - void * m_map = nullptr; + void * m_map = nullptr; public: bool Init(CSwapChainProcessor * swapChain, unsigned frameIndex, uint8_t * base, size_t size); @@ -52,5 +55,16 @@ class CFrameBufferResource size_t GetFrameSize() { return m_frameSize; } void * GetMap() { return m_map; } + void SetTiming(uint64_t captureTime, uint64_t postProcessTime, + uint64_t copyStart) + { + m_captureTime = captureTime; + m_postProcessTime = postProcessTime; + m_copyStart = copyStart; + } + uint64_t GetCaptureTime () const { return m_captureTime; } + uint64_t GetPostProcessTime() const { return m_postProcessTime; } + uint64_t GetCopyStart () const { return m_copyStart; } + ComPtr Get() { return m_res; } }; diff --git a/idd/LGIdd/CIndirectDeviceContext.cpp b/idd/LGIdd/CIndirectDeviceContext.cpp index 63116a21..c9fcb7c3 100644 --- a/idd/LGIdd/CIndirectDeviceContext.cpp +++ b/idd/LGIdd/CIndirectDeviceContext.cpp @@ -212,7 +212,8 @@ void CIndirectDeviceContext::InitAdapter() return; } - if (InterlockedCompareExchange(&m_initInProgress, 1, 0) != 0) + LONG initExpected = 0; + if (!m_initInProgress.compare_exchange_strong(initExpected, 1)) { DEBUG_TRACE("Adapter initialization skipped: initialization already in progress"); return; @@ -227,7 +228,7 @@ void CIndirectDeviceContext::InitAdapter() { DEBUG_WARN("IVSHMEM not available yet, scheduling init retry"); ScheduleInitRetry(); - InterlockedExchange(&m_initInProgress, 0); + m_initInProgress.store(0); return; } m_ivshmemOpened = true; @@ -370,7 +371,7 @@ void CIndirectDeviceContext::InitAdapter() if (!NT_SUCCESS(status)) { DEBUG_ERROR_HR(status, "IddCxAdapterInitAsync Failed"); - InterlockedExchange(&m_initInProgress, 0); + m_initInProgress.store(0); return; } @@ -378,7 +379,7 @@ void CIndirectDeviceContext::InitAdapter() if (!m_adapter) { DEBUG_ERROR("IddCxAdapterInitAsync succeeded without returning an adapter object"); - InterlockedExchange(&m_initInProgress, 0); + m_initInProgress.store(0); return; } @@ -401,7 +402,7 @@ void CIndirectDeviceContext::InitAdapter() // Adapter is up; no need to keep retrying. StopInitRetry(); - InterlockedExchange(&m_initInProgress, 0); + m_initInProgress.store(0); DEBUG_INFO("Adapter initialization request complete; returning to IddCx"); } @@ -501,7 +502,7 @@ void CIndirectDeviceContext::ReplugMonitor() ReleaseSRWLockExclusive(&m_stateLock); // Either no monitor yet, or one is already pending; build it now and // cancel any queued rebuild so we do not create two. - InterlockedExchange(&m_finishInitQueued, 0); + m_finishInitQueued.store(0); FinishInit(0); return; } @@ -537,7 +538,7 @@ void CIndirectDeviceContext::ReplugMonitor() // If there was no swap chain there will be no unassign callback to queue the // rebuild. Otherwise OnSwapChainReleased does so after teardown has drained. if (rebuild) - InterlockedExchange(&m_finishInitQueued, 1); + m_finishInitQueued.store(1); } void CIndirectDeviceContext::OnMonitorDestroyed(IDDCX_MONITOR monitor) @@ -571,7 +572,7 @@ void CIndirectDeviceContext::OnSwapChainReleased() ReleaseSRWLockExclusive(&m_stateLock); if (rebuild) - InterlockedExchange(&m_finishInitQueued, 1); + m_finishInitQueued.store(1); } void CIndirectDeviceContext::OnSwapChainReady() @@ -613,7 +614,7 @@ void CIndirectDeviceContext::OnSwapChainReady() g_pipe.SetDeviceContext(this); if (replug) - InterlockedExchange(&m_replugQueued, 1); + m_replugQueued.store(1); else if (doSetMode) g_pipe.SetDisplayMode(mode.width, mode.height, mode.refresh); } @@ -1100,7 +1101,7 @@ bool CIndirectDeviceContext::SetupLGMP(size_t alignSize) void CIndirectDeviceContext::DeInitLGMP() { - InterlockedExchange(&m_publishedFrameIndex, -1); + m_publishedFrameIndex.store(-1); // The retry timer callback dereferences this context, so make sure it is // stopped and drained before we tear anything down. Wait for any in-flight @@ -1135,13 +1136,13 @@ void CIndirectDeviceContext::DeInitLGMP() void CIndirectDeviceContext::LGMPTimer() { // Rebuild the monitor queued by ReplugMonitor, off the IddCx callback thread. - if (InterlockedExchange(&m_finishInitQueued, 0)) + if (m_finishInitQueued.exchange(0)) { FinishInit(0); return; } - if (InterlockedExchange(&m_replugQueued, 0)) + if (m_replugQueued.exchange(0)) { ReplugMonitor(); return; @@ -1188,8 +1189,7 @@ void CIndirectDeviceContext::LGMPTimer() if (lgmpHostQueueNewSubs(m_frameQueue) && m_monitor) { - const LONG frameIndex = - InterlockedCompareExchange(&m_publishedFrameIndex, 0, 0); + const LONG frameIndex = m_publishedFrameIndex.load(); if (frameIndex >= 0) lgmpHostQueuePost(m_frameQueue, 0, m_frameMemory[frameIndex]); } @@ -1299,6 +1299,11 @@ CIndirectDeviceContext::PreparedFrameBuffer CIndirectDeviceContext::PrepareFrame // fi->offset is initialized at startup fi->flags = flags; fi->sdrWhiteLevel = dstFormat.sdrWhiteLevel; + fi->captureTime = 0; + fi->postProcessTime = 0; + fi->copyTime = 0; + fi->timingSerial = 0; + InterlockedExchange((volatile LONG *)&fi->timingValid, 0); fi->rotation = FRAME_ROT_0; fi->type = dstFormat.format; @@ -1351,7 +1356,7 @@ bool CIndirectDeviceContext::PublishFrameBuffer(unsigned frameIndex) /* Make resends select this submitted frame before posting it. This prevents * a new subscriber racing publication from receiving the previous frame * after the new one. */ - InterlockedExchange(&m_publishedFrameIndex, (LONG)frameIndex); + m_publishedFrameIndex.store(static_cast(frameIndex)); const LGMP_STATUS status = lgmpHostQueuePost(m_frameQueue, 0, m_frameMemory[frameIndex]); @@ -1364,6 +1369,20 @@ bool CIndirectDeviceContext::PublishFrameBuffer(unsigned frameIndex) return true; } +void CIndirectDeviceContext::SetFrameTiming(unsigned frameIndex, + uint64_t captureTime, uint64_t postProcessTime, uint64_t copyTime) +{ + if (frameIndex >= LGMP_Q_FRAME_LEN) + return; + + KVMFRFrame * frame = m_frame[frameIndex]; + frame->captureTime = captureTime; + frame->postProcessTime = postProcessTime; + frame->copyTime = copyTime; + frame->timingSerial = frame->frameSerial; + InterlockedExchange((volatile LONG *)&frame->timingValid, 1); +} + void CIndirectDeviceContext::WriteFrameBuffer(unsigned frameIndex, void* src, size_t offset, size_t len, bool setWritePos) const { FrameBuffer * fb = m_frameBuffer[frameIndex]; diff --git a/idd/LGIdd/CIndirectDeviceContext.h b/idd/LGIdd/CIndirectDeviceContext.h index bf175e53..005818ff 100644 --- a/idd/LGIdd/CIndirectDeviceContext.h +++ b/idd/LGIdd/CIndirectDeviceContext.h @@ -23,6 +23,7 @@ #include #include #include +#include #include #include "CIVSHMEM.h" @@ -78,9 +79,9 @@ private: // Retry state for InitAdapter. At boot the IVSHMEM device may not have // enumerated yet; if so we re-attempt from a timer instead of giving up. - WDFTIMER m_initTimer = nullptr; - bool m_ivshmemOpened = false; - volatile LONG m_initInProgress = 0; + WDFTIMER m_initTimer = nullptr; + bool m_ivshmemOpened = false; + std::atomic m_initInProgress = 0; CIVSHMEM m_ivshmem; @@ -99,16 +100,16 @@ private: bool m_cursorVisible = false; int m_cursorX = 0, m_cursorY = 0; - size_t m_alignSize = 0; - size_t m_frameMemoryOffset = 0; - size_t m_maxFrameSize = 0; - int m_frameIndex = 0; - volatile LONG m_publishedFrameIndex = -1; - uint32_t m_formatVer = 0; - uint32_t m_frameSerial = 0; - PLGMPMemory m_frameMemory[LGMP_Q_FRAME_LEN] = {}; - KVMFRFrame * m_frame [LGMP_Q_FRAME_LEN] = {}; - FrameBuffer * m_frameBuffer[LGMP_Q_FRAME_LEN] = {}; + size_t m_alignSize = 0; + size_t m_frameMemoryOffset = 0; + size_t m_maxFrameSize = 0; + int m_frameIndex = 0; + std::atomic m_publishedFrameIndex = -1; + uint32_t m_formatVer = 0; + uint32_t m_frameSerial = 0; + PLGMPMemory m_frameMemory[LGMP_Q_FRAME_LEN] = {}; + KVMFRFrame * m_frame [LGMP_Q_FRAME_LEN] = {}; + FrameBuffer * m_frameBuffer[LGMP_Q_FRAME_LEN] = {}; unsigned m_width = 0; unsigned m_height = 0; @@ -164,8 +165,8 @@ private: // Set by ReplugMonitor after a departure to rebuild the monitor from the LGMP // timer, off the IddCx callback thread. - volatile LONG m_finishInitQueued = 0; - volatile LONG m_replugQueued = 0; + std::atomic m_finishInitQueued = 0; + std::atomic m_replugQueued = 0; public: CIndirectDeviceContext(_In_ WDFDEVICE wdfDevice) : @@ -216,6 +217,8 @@ public: bool FrameBufferAvailable() const; 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); void WriteFrameBuffer(unsigned frameIndex, void* src, size_t offset, size_t len, bool setWritePos) const; void FinalizeFrameBuffer(unsigned frameIndex) const; diff --git a/idd/LGIdd/CSwapChainProcessor.cpp b/idd/LGIdd/CSwapChainProcessor.cpp index 1f82da94..b6cf2029 100644 --- a/idd/LGIdd/CSwapChainProcessor.cpp +++ b/idd/LGIdd/CSwapChainProcessor.cpp @@ -28,6 +28,22 @@ static const uint32_t HDR_PQ_MIN_LUMINANCE = 50; static const uint32_t HDR_PQ_MAX_LUMINANCE = 10000; +static uint64_t Nanotime() +{ + static const uint64_t frequency = []() + { + LARGE_INTEGER value; + QueryPerformanceFrequency(&value); + return (uint64_t)value.QuadPart; + }(); + + LARGE_INTEGER counter; + QueryPerformanceCounter(&counter); + const uint64_t ticks = (uint64_t)counter.QuadPart; + return ticks / frequency * 1000000000ULL + + ticks % frequency * 1000000000ULL / frequency; +} + CSwapChainProcessor::CSwapChainProcessor(CIndirectMonitorContext * monitorContext, UINT64 assignmentGeneration, IDDCX_MONITOR monitor, CIndirectDeviceContext* devContext, IDDCX_SWAPCHAIN hSwapChain, @@ -192,6 +208,7 @@ bool CSwapChainProcessor::SwapChainThreadCore() // path HDR is not available, so default to SDR. DXGI_COLOR_SPACE_TYPE colorSpace = DXGI_COLOR_SPACE_RGB_FULL_G22_NONE_P709; UINT sdrWhiteLevel = KVMFR_SDR_WHITE_LEVEL_DEFAULT; + const uint64_t captureStart = Nanotime(); #ifdef HAS_IDDCX_110 if (m_devContext->HasIddCx110DDIs()) @@ -252,7 +269,8 @@ bool CSwapChainProcessor::SwapChainThreadCore() if (frameNumber != lastFrameNumber) { lastFrameNumber = frameNumber; - if (!SwapChainNewFrame(surface, dirtyRectCount, colorSpace, sdrWhiteLevel)) + if (!SwapChainNewFrame(surface, dirtyRectCount, colorSpace, + sdrWhiteLevel, Nanotime() - captureStart)) DEBUG_WARN("Failed to submit frame"); } @@ -286,16 +304,21 @@ void CSwapChainProcessor::CompletionFunction( // fail gracefully if (!result) { + sc->m_devContext->SetFrameTiming(fbRes->GetFrameIndex(), + fbRes->GetCaptureTime(), fbRes->GetPostProcessTime(), + Nanotime() - fbRes->GetCopyStart()); sc->m_devContext->FinalizeFrameBuffer(fbRes->GetFrameIndex()); return; } if (sc->m_dx12Device->IsIndirectCopy()) sc->m_devContext->WriteFrameBuffer( - fbRes->GetFrameIndex(), - fbRes->GetMap(), 0, fbRes->GetFrameSize(), true); - else - sc->m_devContext->FinalizeFrameBuffer(fbRes->GetFrameIndex()); + fbRes->GetFrameIndex(), fbRes->GetMap(), 0, fbRes->GetFrameSize(), false); + + const uint64_t copyTime = Nanotime() - fbRes->GetCopyStart(); + sc->m_devContext->SetFrameTiming(fbRes->GetFrameIndex(), + fbRes->GetCaptureTime(), fbRes->GetPostProcessTime(), copyTime); + sc->m_devContext->FinalizeFrameBuffer(fbRes->GetFrameIndex()); } @@ -470,8 +493,9 @@ bool CSwapChainProcessor::GetContentHDRMetadata(D12FrameFormat& format) const #endif } -bool CSwapChainProcessor::SwapChainNewFrame(ComPtr acquiredBuffer, unsigned dirtyRectCount, - DXGI_COLOR_SPACE_TYPE colorSpace, UINT sdrWhiteLevel) +bool CSwapChainProcessor::SwapChainNewFrame(ComPtr acquiredBuffer, + unsigned dirtyRectCount, DXGI_COLOR_SPACE_TYPE colorSpace, + UINT sdrWhiteLevel, uint64_t captureTime) { // Preserve the fast drop path: never hold an IddCx frame while waiting for // a slow or disconnected client. We have not read its rectangles, so force @@ -482,6 +506,8 @@ bool CSwapChainProcessor::SwapChainNewFrame(ComPtr acquiredBuffer return true; } + const uint64_t postProcessStart = Nanotime(); + ComPtr texture; HRESULT hr = acquiredBuffer.As(&texture); if (FAILED(hr)) @@ -708,6 +734,9 @@ bool CSwapChainProcessor::SwapChainNewFrame(ComPtr acquiredBuffer return false; } + const uint64_t copyStart = Nanotime(); + fbRes->SetTiming(captureTime, copyStart - postProcessStart, copyStart); + copyQueue->SetCompletionCallback(&CompletionFunction, this, fbRes); D3D12_TEXTURE_COPY_LOCATION srcLoc = {}; diff --git a/idd/LGIdd/CSwapChainProcessor.h b/idd/LGIdd/CSwapChainProcessor.h index e17f92a7..d5d8b0d5 100644 --- a/idd/LGIdd/CSwapChainProcessor.h +++ b/idd/LGIdd/CSwapChainProcessor.h @@ -102,7 +102,7 @@ private: #endif bool GetContentHDRMetadata(D12FrameFormat& format) const; bool SwapChainNewFrame(ComPtr acquiredBuffer, unsigned dirtyRectCount, - DXGI_COLOR_SPACE_TYPE colorSpace, UINT sdrWhiteLevel); + DXGI_COLOR_SPACE_TYPE colorSpace, UINT sdrWhiteLevel, uint64_t captureTime); public: CSwapChainProcessor(CIndirectMonitorContext * monitorContext, UINT64 assignmentGeneration,