From ea6e155bbfb1cdfda49d439a55f72a2209816f79 Mon Sep 17 00:00:00 2001 From: Geoffrey McRae Date: Thu, 6 Aug 2026 17:29:44 +1000 Subject: [PATCH] [client] metrics: correlate Wayland presentation timing --- client/displayservers/Wayland/gl.c | 20 +- client/displayservers/Wayland/presentation.c | 249 ++++++++++++++++--- client/displayservers/Wayland/wayland.c | 2 +- client/displayservers/Wayland/wayland.h | 21 +- client/displayservers/X11/x11.c | 11 +- client/include/app.h | 5 +- client/include/interface/displayserver.h | 3 +- client/include/interface/renderer.h | 3 +- client/renderers/EGL/egl.c | 6 +- client/src/app.c | 6 +- client/src/main.c | 64 ++++- 11 files changed, 327 insertions(+), 63 deletions(-) diff --git a/client/displayservers/Wayland/gl.c b/client/displayservers/Wayland/gl.c index 3719c805..75f85b0b 100644 --- a/client/displayservers/Wayland/gl.c +++ b/client/displayservers/Wayland/gl.c @@ -28,6 +28,7 @@ #include "app.h" #include "common/debug.h" +#include "common/time.h" #include "util.h" #if defined(ENABLE_EGL) || defined(ENABLE_OPENGL) @@ -229,9 +230,12 @@ static const struct wp_image_description_v1_listener hdrImageDescListener = }; bool waylandEGLSwapBuffers(EGLDisplay display, EGLSurface surface, - const struct Rect * damage, int count) + const struct Rect * damage, int count, uint64_t frameToken, + uint64_t * swapTime, bool * presentTracked) { - bool result = false; + bool result = false; + *swapTime = 0; + *presentTracked = false; // EGL presentation sends a batch of Wayland requests ending in a surface // commit. A concurrent commit would apply a partial batch and, when explicit @@ -249,10 +253,15 @@ bool waylandEGLSwapBuffers(EGLDisplay display, EGLSurface surface, swapWithDamageInit(&wlWm.swapWithDamage, display); } - waylandPresentationFrame(); + struct WaylandPresentationFrame * presentationFrame = + waylandPresentationFrame(frameToken); applyHDRPending(); + const uint64_t swapStart = nanotime(); result = swapWithDamage( &wlWm.swapWithDamage, display, surface, damage, count); + *swapTime = nanotime() - swapStart; + waylandPresentationSwapDone( + presentationFrame, result, presentTracked); if (result) activateReadyHDRImageDesc(); }); @@ -756,6 +765,9 @@ void waylandGLSetSwapInterval(int interval) void waylandGLSwapBuffers(void) { - (void)waylandEGLSwapBuffers(wlWm.glDisplay, wlWm.glSurface, NULL, 0); + uint64_t swapTime = 0; + bool presentTracked = false; + (void)waylandEGLSwapBuffers(wlWm.glDisplay, wlWm.glSurface, NULL, 0, 0, + &swapTime, &presentTracked); } #endif diff --git a/client/displayservers/Wayland/presentation.c b/client/displayservers/Wayland/presentation.c index c850c875..a97ffdf7 100644 --- a/client/displayservers/Wayland/presentation.c +++ b/client/displayservers/Wayland/presentation.c @@ -30,11 +30,77 @@ #include "common/debug.h" #include "common/time.h" -struct FrameData +struct WaylandPresentationFrame { - struct timespec sent; + atomic_uint refs; + struct wl_list link; + struct wp_presentation_feedback * feedback; + uint64_t frameToken; + struct timespec sent; + struct timespec swapReturn; + struct timespec presented; + bool swapDone; + bool swapValid; + bool feedbackDone; + bool feedbackValid; + bool timingComplete; }; +struct PresentationCompletion +{ + uint64_t frameToken; + uint64_t presentTime; + bool notify; + bool valid; +}; + +static void presentationFrameRelease(struct WaylandPresentationFrame * frame) +{ + if (atomic_fetch_sub_explicit( + &frame->refs, 1, memory_order_acq_rel) == 1) + free(frame); +} + +static bool presentationOrdered(const struct timespec * left, + const struct timespec * right) +{ + return left->tv_sec > right->tv_sec || + (left->tv_sec == right->tv_sec && left->tv_nsec >= right->tv_nsec); +} + +static uint64_t presentationDelta(const struct timespec * left, + const struct timespec * right) +{ + struct timespec delta; + tsDiff(&delta, left, right); + return (uint64_t)delta.tv_sec * 1000000000ULL + delta.tv_nsec; +} + +static void presentationCompleteLocked( + struct WaylandPresentationFrame * frame, + struct PresentationCompletion * completion) +{ + if (frame->timingComplete || !frame->swapDone || !frame->feedbackDone) + return; + + frame->timingComplete = true; + completion->notify = frame->frameToken != 0; + completion->frameToken = frame->frameToken; + completion->valid = frame->swapValid && frame->feedbackValid && + presentationOrdered(&frame->presented, &frame->swapReturn); + if (completion->valid) + completion->presentTime = presentationDelta( + &frame->presented, &frame->swapReturn); +} + +static void presentationNotify( + const struct PresentationCompletion * completion) +{ + if (completion->notify) + app_handleFramePresented(completion->frameToken, + completion->presentTime, completion->valid); +} + static void presentationClockId(void * data, struct wp_presentation * presentation, uint32_t clkId) { @@ -57,18 +123,34 @@ static void presentationFeedbackPresented(void * opaque, struct wp_presentation_feedback * feedback, uint32_t tvSecHi, uint32_t tvSecLo, uint32_t tvNsec, uint32_t refresh, uint32_t seqHi, uint32_t seqLo, uint32_t flags) { - struct FrameData * data = opaque; - struct timespec present = { + struct WaylandPresentationFrame * frame = opaque; + const struct timespec present = { .tv_sec = (uint64_t) tvSecHi << 32 | tvSecLo, .tv_nsec = tvNsec, }; - struct timespec delta; + struct PresentationCompletion completion = {}; - tsDiff(&delta, &present, &data->sent); - ringbuffer_push(wlWm.photonTimings, - &(float){ delta.tv_sec * 1e3f + delta.tv_nsec * 1e-6f }); - free(data); + if (tvNsec < 1000000000) + { + struct timespec delta; + tsDiff(&delta, &present, &frame->sent); + ringbuffer_push(wlWm.photonTimings, + &(float){ delta.tv_sec * 1e3f + delta.tv_nsec * 1e-6f }); + } + + INTERLOCKED_SECTION(wlWm.presentationLock, + { + wl_list_remove(&frame->link); + frame->feedback = NULL; + frame->feedbackDone = true; + frame->feedbackValid = tvNsec < 1000000000; + frame->presented = present; + presentationCompleteLocked(frame, &completion); + }); + + presentationNotify(&completion); wp_presentation_feedback_destroy(feedback); + presentationFrameRelease(frame); } bool waylandGetFramePeriod(uint64_t * period) @@ -82,8 +164,21 @@ bool waylandGetFramePeriod(uint64_t * period) static void presentationFeedbackDiscarded(void * data, struct wp_presentation_feedback * feedback) { - free(data); + struct WaylandPresentationFrame * frame = data; + struct PresentationCompletion completion = {}; + + INTERLOCKED_SECTION(wlWm.presentationLock, + { + wl_list_remove(&frame->link); + frame->feedback = NULL; + frame->feedbackDone = true; + frame->feedbackValid = false; + presentationCompleteLocked(frame, &completion); + }); + + presentationNotify(&completion); wp_presentation_feedback_destroy(feedback); + presentationFrameRelease(frame); } static const struct wp_presentation_feedback_listener presentationFeedbackListener = { @@ -94,10 +189,13 @@ static const struct wp_presentation_feedback_listener presentationFeedbackListen bool waylandPresentationInit(void) { + LG_LOCK_INIT(wlWm.presentationLock); + wl_list_init(&wlWm.presentationFrames); + atomic_store_explicit( + &wlWm.presentationClockValid, false, memory_order_release); + if (wlWm.presentation) { - atomic_store_explicit( - &wlWm.presentationClockValid, false, memory_order_release); wlWm.photonTimings = ringbuffer_new(256, sizeof(float)); wlWm.photonGraph = app_registerGraph("PHOTON", wlWm.photonTimings, 0.0f, 30.0f, NULL); @@ -109,36 +207,129 @@ bool waylandPresentationInit(void) void waylandPresentationFree(void) { - if (!wlWm.presentation) - return; - atomic_store_explicit( &wlWm.presentationClockValid, false, memory_order_release); - wp_presentation_destroy(wlWm.presentation); - app_unregisterGraph(wlWm.photonGraph); - ringbuffer_free(&wlWm.photonTimings); + + for (;;) + { + struct WaylandPresentationFrame * frame = NULL; + struct wp_presentation_feedback * feedback = NULL; + struct PresentationCompletion completion = {}; + + LG_LOCK(wlWm.presentationLock); + if (!wl_list_empty(&wlWm.presentationFrames)) + { + frame = wl_container_of( + wlWm.presentationFrames.next, frame, link); + wl_list_remove(&frame->link); + feedback = frame->feedback; + frame->feedback = NULL; + frame->swapDone = true; + frame->swapValid = false; + frame->feedbackDone = true; + frame->feedbackValid = false; + presentationCompleteLocked(frame, &completion); + } + LG_UNLOCK(wlWm.presentationLock); + + if (!frame) + break; + + presentationNotify(&completion); + wp_presentation_feedback_destroy(feedback); + presentationFrameRelease(frame); + } + + if (wlWm.presentation) + { + wp_presentation_destroy(wlWm.presentation); + wlWm.presentation = NULL; + app_unregisterGraph(wlWm.photonGraph); + ringbuffer_free(&wlWm.photonTimings); + } + LG_LOCK_FREE(wlWm.presentationLock); } -void waylandPresentationFrame(void) +struct WaylandPresentationFrame * waylandPresentationFrame( + uint64_t frameToken) { if (!wlWm.presentation || !atomic_load_explicit( &wlWm.presentationClockValid, memory_order_acquire)) - return; + return NULL; - struct FrameData * data = malloc(sizeof(*data)); - if (!data) + struct WaylandPresentationFrame * frame = calloc(1, sizeof(*frame)); + if (!frame) { DEBUG_ERROR("out of memory"); - return; + return NULL; } - if (clock_gettime(wlWm.clkId, &data->sent)) + if (clock_gettime(wlWm.clkId, &frame->sent)) { - DEBUG_ERROR("clock_gettime failed: %s\n", strerror(errno)); - free(data); - return; + DEBUG_ERROR("clock_gettime failed: %s", strerror(errno)); + free(frame); + return NULL; } - struct wp_presentation_feedback * feedback = wp_presentation_feedback(wlWm.presentation, wlWm.surface); - wp_presentation_feedback_add_listener(feedback, &presentationFeedbackListener, data); + frame->feedback = + wp_presentation_feedback(wlWm.presentation, wlWm.surface); + if (!frame->feedback) + { + free(frame); + return NULL; + } + + frame->frameToken = frameToken; + frame->timingComplete = frameToken == 0; + atomic_init(&frame->refs, 2); + if (wp_presentation_feedback_add_listener(frame->feedback, + &presentationFeedbackListener, frame) < 0) + { + wp_presentation_feedback_destroy(frame->feedback); + free(frame); + return NULL; + } + + INTERLOCKED_SECTION(wlWm.presentationLock, + { + wl_list_insert(&wlWm.presentationFrames, &frame->link); + }); + return frame; +} + +void waylandPresentationSwapDone(struct WaylandPresentationFrame * frame, + bool result, bool * presentTracked) +{ + *presentTracked = false; + if (!frame) + return; + + struct timespec swapReturn = {}; + const bool swapValid = result && + clock_gettime(wlWm.clkId, &swapReturn) == 0; + if (result && !swapValid) + DEBUG_ERROR("clock_gettime failed: %s", strerror(errno)); + + struct PresentationCompletion completion = {}; + INTERLOCKED_SECTION(wlWm.presentationLock, + { + frame->swapDone = true; + frame->swapValid = swapValid; + frame->swapReturn = swapReturn; + + if (!swapValid && !frame->timingComplete) + { + frame->timingComplete = true; + completion.notify = true; + completion.frameToken = frame->frameToken; + completion.presentTime = 0; + completion.valid = false; + } + else + presentationCompleteLocked(frame, &completion); + }); + + *presentTracked = result && frame->frameToken != 0; + presentationNotify(&completion); + presentationFrameRelease(frame); } diff --git a/client/displayservers/Wayland/wayland.c b/client/displayservers/Wayland/wayland.c index 11d38527..4005f37c 100644 --- a/client/displayservers/Wayland/wayland.c +++ b/client/displayservers/Wayland/wayland.c @@ -207,8 +207,8 @@ static void waylandShutdown(void) static void waylandFree(void) { waylandIdleFree(); - waylandWindowFree(); waylandPresentationFree(); + waylandWindowFree(); waylandInputFree(); waylandOutputFree(); waylandColorMgmtFree(); diff --git a/client/displayservers/Wayland/wayland.h b/client/displayservers/Wayland/wayland.h index fb64ca02..f088979b 100644 --- a/client/displayservers/Wayland/wayland.h +++ b/client/displayservers/Wayland/wayland.h @@ -160,11 +160,13 @@ struct WaylandDSState #endif struct wp_presentation * presentation; - clockid_t clkId; - _Atomic(bool) presentationClockValid; - _Atomic(uint64_t) nominalPeriod; - RingBuffer photonTimings; - GraphHandle photonGraph; + clockid_t clkId; + _Atomic(bool) presentationClockValid; + LG_Lock presentationLock; + struct wl_list presentationFrames; + _Atomic(uint64_t) nominalPeriod; + RingBuffer photonTimings; + GraphHandle photonGraph; const char * cursorThemeName; int cursorSize; @@ -336,7 +338,8 @@ void waylandCursorScaleChange(void); bool waylandEGLInit(int w, int h); EGLDisplay waylandGetEGLDisplay(void); bool waylandEGLSwapBuffers(EGLDisplay display, EGLSurface surface, - const struct Rect * damage, int count); + const struct Rect * damage, int count, uint64_t frameToken, + uint64_t * swapTime, bool * presentTracked); #endif #ifdef ENABLE_EGL @@ -410,8 +413,12 @@ bool waylandPollRegister(int fd, WaylandPollCallback callback, void * opaque, ui bool waylandPollUnregister(int fd); // presentation module +struct WaylandPresentationFrame; bool waylandPresentationInit(void); -void waylandPresentationFrame(void); +struct WaylandPresentationFrame * waylandPresentationFrame( + uint64_t frameToken); +void waylandPresentationSwapDone(struct WaylandPresentationFrame * frame, + bool result, bool * presentTracked); void waylandPresentationFree(void); bool waylandGetFramePeriod(uint64_t * period); diff --git a/client/displayservers/X11/x11.c b/client/displayservers/X11/x11.c index 62d1b074..8c45d579 100644 --- a/client/displayservers/X11/x11.c +++ b/client/displayservers/X11/x11.c @@ -1661,13 +1661,20 @@ static EGLNativeWindowType x11GetEGLNativeWindow(void) } static bool x11EGLSwapBuffers(EGLDisplay display, EGLSurface surface, - const struct Rect * damage, int count) + const struct Rect * damage, int count, uint64_t frameToken, + uint64_t * swapTime, bool * presentTracked) { static struct SwapWithDamageData data = {0}; if (!data.init) swapWithDamageInit(&data, display); - return swapWithDamage(&data, display, surface, damage, count); + (void)frameToken; + *presentTracked = false; + const uint64_t start = nanotime(); + const bool result = + swapWithDamage(&data, display, surface, damage, count); + *swapTime = nanotime() - start; + return result; } #endif diff --git a/client/include/app.h b/client/include/app.h index 19b3bd77..82506af7 100644 --- a/client/include/app.h +++ b/client/include/app.h @@ -88,6 +88,8 @@ void app_handleGrabEvent(bool active); void app_handleFocusEvent(bool focused); void app_handleCloseEvent(void); void app_handleRenderEvent(const uint64_t timeUs); +void app_handleFramePresented(uint64_t frameToken, uint64_t presentTime, + bool valid); void app_setFullscreen(bool fs); bool app_getFullscreen(void); @@ -104,7 +106,8 @@ bool app_getHDRDescFailed(void); EGLDisplay app_getEGLDisplay(void); EGLNativeWindowType app_getEGLNativeWindow(void); bool app_eglSwapBuffers(EGLDisplay display, EGLSurface surface, - const struct Rect * damage, int count); + const struct Rect * damage, int count, uint64_t frameToken, + uint64_t * swapTime, bool * presentTracked); #endif #ifdef ENABLE_OPENGL diff --git a/client/include/interface/displayserver.h b/client/include/interface/displayserver.h index 34cf7d5a..e7713cf9 100644 --- a/client/include/interface/displayserver.h +++ b/client/include/interface/displayserver.h @@ -181,7 +181,8 @@ struct LG_DisplayServerOps EGLDisplay (*getEGLDisplay)(void); EGLNativeWindowType (*getEGLNativeWindow)(void); bool (*eglSwapBuffers)(EGLDisplay display, EGLSurface surface, - const struct Rect * damage, int count); + const struct Rect * damage, int count, uint64_t frameToken, + uint64_t * swapTime, bool * presentTracked); #endif #ifdef ENABLE_OPENGL diff --git a/client/include/interface/renderer.h b/client/include/interface/renderer.h index 94efd4ea..65fa7dec 100644 --- a/client/include/interface/renderer.h +++ b/client/include/interface/renderer.h @@ -148,7 +148,8 @@ typedef struct LG_RendererFrameTiming uint64_t effectsTime; /* post-processing work */ uint64_t desktopTime; /* desktop work, excluding effects */ uint64_t composeTime; /* composition, excluding UI overlay */ - uint64_t swapTime; /* display-server buffer swap */ + uint64_t swapTime; /* actual EGL buffer swap */ + bool presentTracked; /* presentation feedback expected */ } LG_RendererFrameTiming; diff --git a/client/renderers/EGL/egl.c b/client/renderers/EGL/egl.c index 33f23148..7df49244 100644 --- a/client/renderers/EGL/egl.c +++ b/client/renderers/EGL/egl.c @@ -1689,12 +1689,10 @@ static bool egl_render(LG_Renderer * renderer, LG_RendererRotate rotate, const uint64_t composeEnd = nanotime(); timing->composeTime += composeEnd - postOverlayStart; - const uint64_t swapStart = nanotime(); const bool swapResult = app_eglSwapBuffers( this->display, this->surface, damage, - this->noSwapDamage ? 0 : damageIdx); - const uint64_t swapEnd = nanotime(); - timing->swapTime = swapEnd - swapStart; + this->noSwapDamage ? 0 : damageIdx, timing->frameToken, + &timing->swapTime, &timing->presentTracked); if (!swapResult) DEBUG_ERROR("Failed to swap EGL buffers (eglError: 0x%x)", eglGetError()); diff --git a/client/src/app.c b/client/src/app.c index cbc1e994..181c5ce8 100644 --- a/client/src/app.c +++ b/client/src/app.c @@ -839,9 +839,11 @@ EGLNativeWindowType app_getEGLNativeWindow(void) } bool app_eglSwapBuffers(EGLDisplay display, EGLSurface surface, - const struct Rect * damage, int count) + const struct Rect * damage, int count, uint64_t frameToken, + uint64_t * swapTime, bool * presentTracked) { - return g_state.ds->eglSwapBuffers(display, surface, damage, count); + return g_state.ds->eglSwapBuffers(display, surface, damage, count, + frameToken, swapTime, presentTracked); } #endif diff --git a/client/src/main.c b/client/src/main.c index f4b8d54e..432a79fa 100644 --- a/client/src/main.c +++ b/client/src/main.c @@ -204,11 +204,13 @@ static bool tickTimerFn(void * unused) #define FRAME_TIMING_RECORD_COUNT 1024 #define FRAME_TIMING_PUBLISH_BATCH_SIZE 32 +#define FRAME_TIMING_PRESENT_TIMEOUT_NS 500000000ULL enum FrameTimingReady { - FRAME_TIMING_FRAME_READY = 1 << 0, - FRAME_TIMING_RENDER_READY = 1 << 1, + FRAME_TIMING_FRAME_READY = 1 << 0, + FRAME_TIMING_RENDER_READY = 1 << 1, + FRAME_TIMING_PRESENT_READY = 1 << 2, }; struct FrameTimingRecord @@ -222,6 +224,7 @@ struct FrameTimingRecord bool producerValid; bool phaseValid; bool transportValid; + bool presentValid; uint64_t captureTime; uint64_t postProcessTime; @@ -242,6 +245,8 @@ struct FrameTimingRecord uint64_t desktopTime; uint64_t composeTime; uint64_t swapTime; + uint64_t presentTime; + uint64_t presentDeadline; }; static struct @@ -300,6 +305,23 @@ static struct FrameTimingRecord * frameTimingRecord( (token - 1) % FRAME_TIMING_RECORD_COUNT]; } +void app_handleFramePresented(uint64_t frameToken, uint64_t presentTime, + bool valid) +{ + if (!frameToken) + return; + + INTERLOCKED_SECTION(l_frameTiming.lock, { + struct FrameTimingRecord * record = frameTimingRecord(frameToken); + if (record->token == frameToken) + { + record->presentTime = presentTime; + record->presentValid = valid; + record->readyMask |= FRAME_TIMING_PRESENT_READY; + } + }); +} + static LG_RendererFrameToken frameTimingReserve(void) { LG_RendererFrameToken token; @@ -420,12 +442,20 @@ static void frameTimingFinishRender(const LG_RendererFrameTiming * timing, record->prepareTime = prepareTime; if (record->timestamp < timestamp) record->timestamp = timestamp; - record->setupTime = timing->setupTime; - record->effectsTime = timing->effectsTime; - record->desktopTime = timing->desktopTime; - record->composeTime = timing->composeTime; - record->swapTime = timing->swapTime; - record->readyMask |= FRAME_TIMING_RENDER_READY; + record->setupTime = timing->setupTime; + record->effectsTime = timing->effectsTime; + record->desktopTime = timing->desktopTime; + record->composeTime = timing->composeTime; + record->swapTime = timing->swapTime; + record->presentDeadline = timestamp + FRAME_TIMING_PRESENT_TIMEOUT_NS; + if (!timing->presentTracked && + !(record->readyMask & FRAME_TIMING_PRESENT_READY)) + { + record->presentTime = 0; + record->presentValid = false; + record->readyMask |= FRAME_TIMING_PRESENT_READY; + } + record->readyMask |= FRAME_TIMING_RENDER_READY; record->transportValid = record->phaseValid && timing->frameToken == cadenceToken; @@ -474,6 +504,7 @@ static void frameTimingPublishReady(void) unsigned readyCount = 0; LG_LOCK(l_frameTiming.lock); + const uint64_t now = nanotime(); while (readyCount < FRAME_TIMING_PUBLISH_BATCH_SIZE && l_frameTiming.publishCount) { @@ -493,6 +524,16 @@ static void frameTimingPublishReady(void) if (!(record->readyMask & FRAME_TIMING_FRAME_READY)) break; + if (!(record->readyMask & FRAME_TIMING_PRESENT_READY)) + { + if (!record->presentDeadline || now < record->presentDeadline) + break; + + record->presentTime = 0; + record->presentValid = false; + record->readyMask |= FRAME_TIMING_PRESENT_READY; + } + ready[readyCount++] = *record; *record = (struct FrameTimingRecord) {}; l_frameTiming.publishRead = @@ -513,12 +554,13 @@ static void frameTimingPublishReady(void) record->readyLeadTime > transportAccounted ? record->readyLeadTime - transportAccounted : 0; uint32_t validMask = - OVERLAY_FRAME_TIMING_VALID_ALL & - ~OVERLAY_FRAME_TIMING_VALID_PRESENT; + OVERLAY_FRAME_TIMING_VALID_ALL; if (!record->producerValid) validMask &= ~OVERLAY_FRAME_TIMING_VALID_PRODUCER; if (!record->producerValid || !record->transportValid) validMask &= ~OVERLAY_FRAME_TIMING_VALID_TRANSPORT; + if (!record->presentValid) + validMask &= ~OVERLAY_FRAME_TIMING_VALID_PRESENT; const OverlayFrameTiming timing = { .timestamp = record->timestamp, @@ -539,7 +581,7 @@ static void frameTimingPublishReady(void) .desktop = record->desktopTime * 1e-6f, .compose = record->composeTime * 1e-6f, .swap = record->swapTime * 1e-6f, - .present = 0.0f, + .present = record->presentTime * 1e-6f, }; ringbuffer_push(g_state.frameLatency, &timing); }