[client/host/idd/lgmp] add additional timing metrics

This commit is contained in:
Geoffrey McRae
2026-08-03 10:57:32 +10:00
parent 3035fa6282
commit 7533c855c2
18 changed files with 339 additions and 88 deletions

View File

@@ -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. */

View File

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

View File

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

View File

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

View File

@@ -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,