From 4a049a557a7979c6db37ebd353e017cca685dc71 Mon Sep 17 00:00:00 2001 From: Aiden <68633820+awils27@users.noreply.github.com> Date: Tue, 12 May 2026 22:18:27 +1000 Subject: [PATCH] Render timing --- apps/RenderCadenceCompositor/README.md | 14 ++++-- .../app/RenderCadenceApp.h | 36 ++++++++------- .../control/RuntimeStateJson.h | 4 +- .../frames/SystemFrameExchange.cpp | 45 +++++++++++++++++++ .../frames/SystemFrameExchange.h | 4 ++ .../render/RenderThread.cpp | 31 +++++++++++++ .../render/RenderThread.h | 12 +++++ .../render/readback/Bgra8ReadbackPipeline.cpp | 20 ++++++++- .../render/readback/Bgra8ReadbackPipeline.h | 6 +++ .../telemetry/CadenceTelemetry.h | 14 ++++++ .../telemetry/CadenceTelemetryJson.h | 7 +++ docs/openapi.yaml | 23 ++++++++++ ...derCadenceCompositorFrameExchangeTests.cpp | 22 +++++++++ ...CadenceCompositorRuntimeStateJsonTests.cpp | 14 ++++++ .../RenderCadenceCompositorTelemetryTests.cpp | 32 +++++++++++++ 15 files changed, 260 insertions(+), 24 deletions(-) diff --git a/apps/RenderCadenceCompositor/README.md b/apps/RenderCadenceCompositor/README.md index 2db876c..62cb559 100644 --- a/apps/RenderCadenceCompositor/README.md +++ b/apps/RenderCadenceCompositor/README.md @@ -35,7 +35,7 @@ DeckLinkOutputThread never renders ``` -Startup warms up real rendered frames before DeckLink scheduled playback starts. When DeckLink input is available, startup also waits briefly for three ready input frames before the render thread starts so the first render ticks are deliberate rather than lucky. +Startup builds one settled output reserve before DeckLink scheduled playback starts: the completed-frame reserve must reach the configured depth and remain ready for the configured settle window. When DeckLink input is available, startup also waits briefly for three ready input frames before the render thread starts so the first render ticks are deliberate rather than lucky. ## Current Scope @@ -53,8 +53,7 @@ Included now: - render-thread-owned input texture upload - async PBO readback - latest-N system-memory frame exchange -- rendered-frame warmup -- eight completed output warmup frames before DeckLink preroll, with DeckLink scheduled depth still targeted at four +- settled completed-frame output reserve before DeckLink preroll, with DeckLink scheduled depth still targeted at four - background Slang compile of `shaders/happy-accident` - app-owned display/render layer model for shader build readiness - app-owned submission of a completed shader artifact @@ -239,7 +238,7 @@ DeckLink output is an optional edge service in this app. Startup order is: 1. start render thread -2. warm up rendered system-memory frames +2. build a settled completed-frame output reserve at normal render cadence 3. try to attach DeckLink output 4. start telemetry and HTTP either way @@ -282,6 +281,13 @@ Input telemetry: - `inputFramesReceived`: frames accepted into `InputFrameMailbox` - `inputFramesDropped`: ready input frames dropped or missed because the mailbox was full +- `renderFrameMs`: most recent render-thread draw duration, excluding completed-readback copy and readback queue work +- `renderFrameBudgetUsedPercent`: most recent render draw time as a percentage of the selected frame budget +- `renderFrameMaxMs`: maximum observed render-thread draw duration for this process +- `readbackQueueMs`: time spent queueing the most recent async BGRA8 PBO readback +- `completedReadbackCopyMs`: time spent mapping/copying the most recent completed readback into system-memory frame storage +- `completedDrops`: completed unscheduled system-memory frames dropped so render could reuse the slot +- `acquireMisses`: times render/readback could not acquire a writable system-memory frame slot - `inputConsumeMisses`: render ticks where no ready input frame was available to upload - `inputUploadMisses`: input texture upload attempts that reused the previous GL input texture - `inputReadyFrames`: ready input frames currently queued in `InputFrameMailbox` diff --git a/apps/RenderCadenceCompositor/app/RenderCadenceApp.h b/apps/RenderCadenceCompositor/app/RenderCadenceApp.h index fa1291c..7a56d3d 100644 --- a/apps/RenderCadenceCompositor/app/RenderCadenceApp.h +++ b/apps/RenderCadenceCompositor/app/RenderCadenceApp.h @@ -87,29 +87,13 @@ public: } mRuntimeLayers.StartStartupBuild(mConfig.runtimeShaderId); - Log("app", "Waiting for rendered warmup frames."); - if (!mFrameExchange.WaitForCompletedDepth(mConfig.warmupCompletedFrames, mConfig.warmupTimeout)) + if (!BuildSettledOutputReserve(error)) { - error = "Timed out waiting for rendered warmup frames."; LogError("app", error); Stop(); return false; } - if (mConfig.startupSettle > std::chrono::milliseconds::zero()) - { - Log("app", "Settling render cadence before DeckLink output for " + std::to_string(mConfig.startupSettle.count()) + " ms."); - std::this_thread::sleep_for(mConfig.startupSettle); - Log("app", "Waiting for rendered reserve after startup settle."); - if (!mFrameExchange.WaitForCompletedDepth(mConfig.warmupCompletedFrames, mConfig.warmupTimeout)) - { - error = "Timed out waiting for rendered reserve after startup settle."; - LogError("app", error); - Stop(); - return false; - } - } - StartOptionalVideoOutput(); mTelemetryHealth.Start(mFrameExchange, mOutput, mOutputThread, mRenderThread); StartHttpServer(); @@ -181,6 +165,24 @@ private: Log("app", mVideoOutputStatus); } + bool BuildSettledOutputReserve(std::string& error) + { + const auto reserveTimeout = mConfig.warmupTimeout + mConfig.startupSettle + mConfig.warmupTimeout; + Log("app", + "Building settled output reserve: waiting for " + std::to_string(mConfig.warmupCompletedFrames) + + " completed frame(s) to remain ready for " + std::to_string(mConfig.startupSettle.count()) + " ms."); + if (mFrameExchange.WaitForStableCompletedDepth( + mConfig.warmupCompletedFrames, + mConfig.startupSettle, + reserveTimeout)) + { + return true; + } + + error = "Timed out waiting for settled output reserve."; + return false; + } + void DisableVideoOutput(const std::string& reason) { mOutputThread.Stop(); diff --git a/apps/RenderCadenceCompositor/control/RuntimeStateJson.h b/apps/RenderCadenceCompositor/control/RuntimeStateJson.h index d7b2bb5..8cb3fa4 100644 --- a/apps/RenderCadenceCompositor/control/RuntimeStateJson.h +++ b/apps/RenderCadenceCompositor/control/RuntimeStateJson.h @@ -284,9 +284,9 @@ inline std::string RuntimeStateToJson(const RuntimeStateJsonInput& input) writer.Key("performance"); writer.BeginObject(); writer.KeyDouble("frameBudgetMs", FrameDurationMillisecondsFromRateString(input.config.outputFrameRate)); - writer.KeyNull("renderMs"); + writer.KeyDouble("renderMs", input.telemetry.renderFrameMilliseconds); writer.KeyNull("smoothedRenderMs"); - writer.KeyNull("budgetUsedPercent"); + writer.KeyDouble("budgetUsedPercent", input.telemetry.renderFrameBudgetUsedPercent); writer.KeyNull("completionIntervalMs"); writer.KeyNull("smoothedCompletionIntervalMs"); writer.KeyNull("maxCompletionIntervalMs"); diff --git a/apps/RenderCadenceCompositor/frames/SystemFrameExchange.cpp b/apps/RenderCadenceCompositor/frames/SystemFrameExchange.cpp index 46e1e7d..59d3e37 100644 --- a/apps/RenderCadenceCompositor/frames/SystemFrameExchange.cpp +++ b/apps/RenderCadenceCompositor/frames/SystemFrameExchange.cpp @@ -130,6 +130,51 @@ bool SystemFrameExchange::WaitForCompletedDepth(std::size_t targetDepth, std::ch }); } +bool SystemFrameExchange::WaitForStableCompletedDepth( + std::size_t targetDepth, + std::chrono::milliseconds stableDuration, + std::chrono::milliseconds timeout) +{ + if (targetDepth == 0) + return true; + + const auto deadline = std::chrono::steady_clock::now() + timeout; + std::unique_lock lock(mMutex); + bool stableWindowStarted = false; + std::chrono::steady_clock::time_point stableSince; + + while (true) + { + const auto now = std::chrono::steady_clock::now(); + if (now >= deadline) + return false; + + if (CompletedCountLocked() >= targetDepth) + { + if (stableDuration <= std::chrono::milliseconds::zero()) + return true; + + if (!stableWindowStarted) + { + stableSince = now; + stableWindowStarted = true; + } + + const auto stableDeadline = stableSince + stableDuration; + if (now >= stableDeadline) + return true; + + mCondition.wait_until(lock, stableDeadline < deadline ? stableDeadline : deadline); + continue; + } + + stableWindowStarted = false; + mCondition.wait_until(lock, deadline, [&]() { + return CompletedCountLocked() >= targetDepth; + }); + } +} + void SystemFrameExchange::Clear() { std::lock_guard lock(mMutex); diff --git a/apps/RenderCadenceCompositor/frames/SystemFrameExchange.h b/apps/RenderCadenceCompositor/frames/SystemFrameExchange.h index 23041c7..7968b4c 100644 --- a/apps/RenderCadenceCompositor/frames/SystemFrameExchange.h +++ b/apps/RenderCadenceCompositor/frames/SystemFrameExchange.h @@ -22,6 +22,10 @@ public: bool ConsumeCompletedForSchedule(SystemFrame& frame); bool ReleaseScheduledByBytes(void* bytes); bool WaitForCompletedDepth(std::size_t targetDepth, std::chrono::milliseconds timeout); + bool WaitForStableCompletedDepth( + std::size_t targetDepth, + std::chrono::milliseconds stableDuration, + std::chrono::milliseconds timeout); void Clear(); SystemFrameExchangeMetrics Metrics() const; diff --git a/apps/RenderCadenceCompositor/render/RenderThread.cpp b/apps/RenderCadenceCompositor/render/RenderThread.cpp index 05548ed..cd34786 100644 --- a/apps/RenderCadenceCompositor/render/RenderThread.cpp +++ b/apps/RenderCadenceCompositor/render/RenderThread.cpp @@ -85,6 +85,11 @@ RenderThread::Metrics RenderThread::GetMetrics() const metrics.skippedFrames = mSkippedFrames.load(std::memory_order_relaxed); metrics.shaderBuildsCommitted = mShaderBuildsCommitted.load(std::memory_order_relaxed); metrics.shaderBuildFailures = mShaderBuildFailures.load(std::memory_order_relaxed); + metrics.renderFrameMilliseconds = mRenderFrameMilliseconds.load(std::memory_order_relaxed); + metrics.renderFrameBudgetUsedPercent = mRenderFrameBudgetUsedPercent.load(std::memory_order_relaxed); + metrics.renderFrameMaxMilliseconds = mRenderFrameMaxMilliseconds.load(std::memory_order_relaxed); + metrics.readbackQueueMilliseconds = mReadbackQueueMilliseconds.load(std::memory_order_relaxed); + metrics.completedReadbackCopyMilliseconds = mCompletedReadbackCopyMilliseconds.load(std::memory_order_relaxed); metrics.inputFramesReceived = mInputFramesReceived.load(std::memory_order_relaxed); metrics.inputFramesDropped = mInputFramesDropped.load(std::memory_order_relaxed); metrics.inputConsumeMisses = mInputConsumeMisses.load(std::memory_order_relaxed); @@ -154,6 +159,7 @@ void RenderThread::ThreadMain() CountAcquireMiss(); }, [this]() { CountCompleted(); }); + PublishReadbackMetrics(readback); const auto now = RenderCadenceClock::Clock::now(); const RenderCadenceClock::Tick tick = clock.Poll(now); @@ -178,6 +184,7 @@ void RenderThread::ThreadMain() { mPboQueueMisses.fetch_add(1, std::memory_order_relaxed); } + PublishReadbackMetrics(readback); CountRendered(); ++frameIndex; @@ -196,6 +203,7 @@ void RenderThread::ThreadMain() CountAcquireMiss(); }, [this]() { CountCompleted(); }); + PublishReadbackMetrics(readback); } readback.Shutdown(); @@ -237,6 +245,29 @@ void RenderThread::CountAcquireMiss() mAcquireMisses.fetch_add(1, std::memory_order_relaxed); } +void RenderThread::PublishReadbackMetrics(const Bgra8ReadbackPipeline& readback) +{ + const double renderMilliseconds = readback.LastRenderFrameMilliseconds(); + mRenderFrameMilliseconds.store(renderMilliseconds, std::memory_order_relaxed); + if (mConfig.frameDurationMilliseconds > 0.0) + { + mRenderFrameBudgetUsedPercent.store( + (renderMilliseconds / mConfig.frameDurationMilliseconds) * 100.0, + std::memory_order_relaxed); + } + else + { + mRenderFrameBudgetUsedPercent.store(0.0, std::memory_order_relaxed); + } + + const double previousMax = mRenderFrameMaxMilliseconds.load(std::memory_order_relaxed); + if (renderMilliseconds > previousMax) + mRenderFrameMaxMilliseconds.store(renderMilliseconds, std::memory_order_relaxed); + + mReadbackQueueMilliseconds.store(readback.LastReadbackQueueMilliseconds(), std::memory_order_relaxed); + mCompletedReadbackCopyMilliseconds.store(readback.LastCompletedReadbackCopyMilliseconds(), std::memory_order_relaxed); +} + void RenderThread::PublishInputMetrics(const InputFrameTexture& inputTexture) { if (mInputMailbox != nullptr) diff --git a/apps/RenderCadenceCompositor/render/RenderThread.h b/apps/RenderCadenceCompositor/render/RenderThread.h index 3948f47..131e8b9 100644 --- a/apps/RenderCadenceCompositor/render/RenderThread.h +++ b/apps/RenderCadenceCompositor/render/RenderThread.h @@ -16,6 +16,7 @@ class SystemFrameExchange; class InputFrameMailbox; class InputFrameTexture; +class Bgra8ReadbackPipeline; class RenderThread { @@ -38,6 +39,11 @@ public: uint64_t skippedFrames = 0; uint64_t shaderBuildsCommitted = 0; uint64_t shaderBuildFailures = 0; + double renderFrameMilliseconds = 0.0; + double renderFrameBudgetUsedPercent = 0.0; + double renderFrameMaxMilliseconds = 0.0; + double readbackQueueMilliseconds = 0.0; + double completedReadbackCopyMilliseconds = 0.0; uint64_t inputFramesReceived = 0; uint64_t inputFramesDropped = 0; uint64_t inputConsumeMisses = 0; @@ -71,6 +77,7 @@ private: void CountRendered(); void CountCompleted(); void CountAcquireMiss(); + void PublishReadbackMetrics(const Bgra8ReadbackPipeline& readback); void PublishInputMetrics(const InputFrameTexture& inputTexture); void TryCommitReadyRuntimeShader(RuntimeRenderScene& runtimeRenderScene); bool TryTakePendingRuntimeShaderArtifact(RuntimeShaderArtifact& artifact); @@ -96,6 +103,11 @@ private: std::atomic mSkippedFrames{ 0 }; std::atomic mShaderBuildsCommitted{ 0 }; std::atomic mShaderBuildFailures{ 0 }; + std::atomic mRenderFrameMilliseconds{ 0.0 }; + std::atomic mRenderFrameBudgetUsedPercent{ 0.0 }; + std::atomic mRenderFrameMaxMilliseconds{ 0.0 }; + std::atomic mReadbackQueueMilliseconds{ 0.0 }; + std::atomic mCompletedReadbackCopyMilliseconds{ 0.0 }; std::atomic mInputFramesReceived{ 0 }; std::atomic mInputFramesDropped{ 0 }; std::atomic mInputConsumeMisses{ 0 }; diff --git a/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.cpp b/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.cpp index e91d087..3e41240 100644 --- a/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.cpp +++ b/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.cpp @@ -2,8 +2,18 @@ #include "../frames/SystemFrameTypes.h" +#include #include +namespace +{ +double MillisecondsSince(std::chrono::steady_clock::time_point start) +{ + return std::chrono::duration_cast>( + std::chrono::steady_clock::now() - start).count(); +} +} + Bgra8ReadbackPipeline::~Bgra8ReadbackPipeline() { Shutdown(); @@ -50,10 +60,15 @@ bool Bgra8ReadbackPipeline::RenderAndQueue(uint64_t frameIndex, const RenderCall return false; glBindFramebuffer(GL_FRAMEBUFFER, mFramebuffer); + const auto renderStart = std::chrono::steady_clock::now(); renderFrame(frameIndex); + mLastRenderFrameMilliseconds = MillisecondsSince(renderStart); glBindFramebuffer(GL_FRAMEBUFFER, 0); - return mPboRing.QueueReadback(mFramebuffer, mWidth, mHeight, frameIndex); + const auto queueStart = std::chrono::steady_clock::now(); + const bool queued = mPboRing.QueueReadback(mFramebuffer, mWidth, mHeight, frameIndex); + mLastReadbackQueueMilliseconds = MillisecondsSince(queueStart); + return queued; } void Bgra8ReadbackPipeline::ConsumeCompleted( @@ -68,12 +83,14 @@ void Bgra8ReadbackPipeline::ConsumeCompleted( PboReadbackRing::CompletedReadback readback; while (mPboRing.TryAcquireCompleted(readback)) { + const auto copyStart = std::chrono::steady_clock::now(); glBindBuffer(GL_PIXEL_PACK_BUFFER, readback.pbo); void* mapped = glMapBuffer(GL_PIXEL_PACK_BUFFER, GL_READ_ONLY); if (!mapped) { glBindBuffer(GL_PIXEL_PACK_BUFFER, 0); mPboRing.ReleaseCompleted(readback); + mLastCompletedReadbackCopyMilliseconds = MillisecondsSince(copyStart); continue; } @@ -99,6 +116,7 @@ void Bgra8ReadbackPipeline::ConsumeCompleted( glUnmapBuffer(GL_PIXEL_PACK_BUFFER); glBindBuffer(GL_PIXEL_PACK_BUFFER, 0); mPboRing.ReleaseCompleted(readback); + mLastCompletedReadbackCopyMilliseconds = MillisecondsSince(copyStart); } } diff --git a/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.h b/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.h index 4be11ba..5768912 100644 --- a/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.h +++ b/apps/RenderCadenceCompositor/render/readback/Bgra8ReadbackPipeline.h @@ -38,6 +38,9 @@ public: unsigned RowBytes() const { return mRowBytes; } VideoIOPixelFormat PixelFormat() const { return VideoIOPixelFormat::Bgra8; } uint64_t PboQueueMisses() const { return mPboRing.QueueMisses(); } + double LastRenderFrameMilliseconds() const { return mLastRenderFrameMilliseconds; } + double LastReadbackQueueMilliseconds() const { return mLastReadbackQueueMilliseconds; } + double LastCompletedReadbackCopyMilliseconds() const { return mLastCompletedReadbackCopyMilliseconds; } private: bool CreateRenderTarget(); @@ -48,5 +51,8 @@ private: unsigned mRowBytes = 0; GLuint mFramebuffer = 0; GLuint mTexture = 0; + double mLastRenderFrameMilliseconds = 0.0; + double mLastReadbackQueueMilliseconds = 0.0; + double mLastCompletedReadbackCopyMilliseconds = 0.0; PboReadbackRing mPboRing; }; diff --git a/apps/RenderCadenceCompositor/telemetry/CadenceTelemetry.h b/apps/RenderCadenceCompositor/telemetry/CadenceTelemetry.h index cd1750c..7236c7d 100644 --- a/apps/RenderCadenceCompositor/telemetry/CadenceTelemetry.h +++ b/apps/RenderCadenceCompositor/telemetry/CadenceTelemetry.h @@ -19,6 +19,8 @@ struct CadenceTelemetrySnapshot uint64_t scheduledTotal = 0; uint64_t completedPollMisses = 0; uint64_t scheduleFailures = 0; + uint64_t completedDrops = 0; + uint64_t acquireMisses = 0; uint64_t completions = 0; uint64_t displayedLate = 0; uint64_t dropped = 0; @@ -26,6 +28,11 @@ struct CadenceTelemetrySnapshot uint64_t clockSkippedFrames = 0; uint64_t shaderBuildsCommitted = 0; uint64_t shaderBuildFailures = 0; + double renderFrameMilliseconds = 0.0; + double renderFrameBudgetUsedPercent = 0.0; + double renderFrameMaxMilliseconds = 0.0; + double readbackQueueMilliseconds = 0.0; + double completedReadbackCopyMilliseconds = 0.0; uint64_t inputFramesReceived = 0; uint64_t inputFramesDropped = 0; uint64_t inputConsumeMisses = 0; @@ -77,6 +84,8 @@ public: snapshot.scheduleFailures = outputMetrics.scheduleFailures > threadMetrics.scheduleFailures ? outputMetrics.scheduleFailures : threadMetrics.scheduleFailures; + snapshot.completedDrops = exchangeMetrics.completedDrops; + snapshot.acquireMisses = exchangeMetrics.acquireMisses; snapshot.completions = outputMetrics.completions; snapshot.displayedLate = outputMetrics.displayedLate; snapshot.dropped = outputMetrics.dropped; @@ -110,6 +119,11 @@ public: snapshot.clockSkippedFrames = renderMetrics.skippedFrames; snapshot.shaderBuildsCommitted = renderMetrics.shaderBuildsCommitted; snapshot.shaderBuildFailures = renderMetrics.shaderBuildFailures; + snapshot.renderFrameMilliseconds = renderMetrics.renderFrameMilliseconds; + snapshot.renderFrameBudgetUsedPercent = renderMetrics.renderFrameBudgetUsedPercent; + snapshot.renderFrameMaxMilliseconds = renderMetrics.renderFrameMaxMilliseconds; + snapshot.readbackQueueMilliseconds = renderMetrics.readbackQueueMilliseconds; + snapshot.completedReadbackCopyMilliseconds = renderMetrics.completedReadbackCopyMilliseconds; snapshot.inputFramesReceived = renderMetrics.inputFramesReceived; snapshot.inputFramesDropped = renderMetrics.inputFramesDropped; snapshot.inputConsumeMisses = renderMetrics.inputConsumeMisses; diff --git a/apps/RenderCadenceCompositor/telemetry/CadenceTelemetryJson.h b/apps/RenderCadenceCompositor/telemetry/CadenceTelemetryJson.h index 4b0882c..d159743 100644 --- a/apps/RenderCadenceCompositor/telemetry/CadenceTelemetryJson.h +++ b/apps/RenderCadenceCompositor/telemetry/CadenceTelemetryJson.h @@ -21,6 +21,8 @@ inline void WriteCadenceTelemetryJson(JsonWriter& writer, const CadenceTelemetry writer.KeyUInt("scheduledTotal", snapshot.scheduledTotal); writer.KeyUInt("completedPollMisses", snapshot.completedPollMisses); writer.KeyUInt("scheduleFailures", snapshot.scheduleFailures); + writer.KeyUInt("completedDrops", snapshot.completedDrops); + writer.KeyUInt("acquireMisses", snapshot.acquireMisses); writer.KeyUInt("completions", snapshot.completions); writer.KeyUInt("late", snapshot.displayedLate); writer.KeyUInt("dropped", snapshot.dropped); @@ -30,6 +32,11 @@ inline void WriteCadenceTelemetryJson(JsonWriter& writer, const CadenceTelemetry writer.KeyUInt("clockSkipped", snapshot.clockSkippedFrames); writer.KeyUInt("shaderCommitted", snapshot.shaderBuildsCommitted); writer.KeyUInt("shaderFailures", snapshot.shaderBuildFailures); + writer.KeyDouble("renderFrameMs", snapshot.renderFrameMilliseconds); + writer.KeyDouble("renderFrameBudgetUsedPercent", snapshot.renderFrameBudgetUsedPercent); + writer.KeyDouble("renderFrameMaxMs", snapshot.renderFrameMaxMilliseconds); + writer.KeyDouble("readbackQueueMs", snapshot.readbackQueueMilliseconds); + writer.KeyDouble("completedReadbackCopyMs", snapshot.completedReadbackCopyMilliseconds); writer.KeyUInt("inputFramesReceived", snapshot.inputFramesReceived); writer.KeyUInt("inputFramesDropped", snapshot.inputFramesDropped); writer.KeyUInt("inputConsumeMisses", snapshot.inputConsumeMisses); diff --git a/docs/openapi.yaml b/docs/openapi.yaml index 155b07a..ea47c36 100644 --- a/docs/openapi.yaml +++ b/docs/openapi.yaml @@ -635,10 +635,12 @@ components: type: number renderMs: type: number + description: Alias of cadence.renderFrameMs for clients that read the top-level performance object. smoothedRenderMs: type: number budgetUsedPercent: type: number + description: Alias of cadence.renderFrameBudgetUsedPercent for clients that read the top-level performance object. completionIntervalMs: type: number smoothedCompletionIntervalMs: @@ -670,6 +672,27 @@ components: type: number deprecated: true description: Deprecated alias for clockSkippedFrames. + renderFrameMs: + type: number + description: Most recent render-thread frame draw duration in milliseconds, excluding completed-readback copy and readback queue work. + renderFrameBudgetUsedPercent: + type: number + description: Most recent render-thread frame draw duration as a percentage of the selected frame budget. + renderFrameMaxMs: + type: number + description: Maximum observed render-thread frame draw duration in milliseconds for this process. + readbackQueueMs: + type: number + description: Most recent duration spent queueing BGRA8 async PBO readback after rendering. + completedReadbackCopyMs: + type: number + description: Most recent duration spent mapping and copying a completed BGRA8 readback into system-memory frame storage. + completedDrops: + type: number + description: Number of completed unscheduled system-memory frames dropped so render could reuse the slot. + acquireMisses: + type: number + description: Number of times render/readback could not acquire a writable system-memory frame slot. inputFramesReceived: type: number inputFramesDropped: diff --git a/tests/RenderCadenceCompositorFrameExchangeTests.cpp b/tests/RenderCadenceCompositorFrameExchangeTests.cpp index 03d32ad..93dbc14 100644 --- a/tests/RenderCadenceCompositorFrameExchangeTests.cpp +++ b/tests/RenderCadenceCompositorFrameExchangeTests.cpp @@ -154,6 +154,26 @@ void TestCompletedPollMissIsCounted() SystemFrameExchangeMetrics metrics = exchange.Metrics(); Expect(metrics.completedPollMisses == 1, "completed poll miss is counted"); } + +void TestStableCompletedDepthCanBeObserved() +{ + SystemFrameExchange exchange(MakeConfig(1)); + SystemFrame frame; + Expect(exchange.AcquireForRender(frame), "stable-depth frame can be acquired"); + Expect(exchange.PublishCompleted(frame), "stable-depth frame can be completed"); + + Expect( + exchange.WaitForStableCompletedDepth(1, std::chrono::milliseconds(1), std::chrono::milliseconds(50)), + "stable completed depth can be observed"); +} + +void TestStableCompletedDepthTimesOut() +{ + SystemFrameExchange exchange(MakeConfig(1)); + Expect( + !exchange.WaitForStableCompletedDepth(1, std::chrono::milliseconds(1), std::chrono::milliseconds(1)), + "missing stable completed depth times out"); +} } int main() @@ -164,6 +184,8 @@ int main() TestGenerationValidationRejectsStaleFrames(); TestPixelFormatAwareSizing(); TestCompletedPollMissIsCounted(); + TestStableCompletedDepthCanBeObserved(); + TestStableCompletedDepthTimesOut(); if (gFailures != 0) { diff --git a/tests/RenderCadenceCompositorRuntimeStateJsonTests.cpp b/tests/RenderCadenceCompositorRuntimeStateJsonTests.cpp index 7836387..14d7839 100644 --- a/tests/RenderCadenceCompositorRuntimeStateJsonTests.cpp +++ b/tests/RenderCadenceCompositorRuntimeStateJsonTests.cpp @@ -43,6 +43,13 @@ int main() RenderCadenceCompositor::CadenceTelemetrySnapshot telemetry; telemetry.renderFps = 59.94; + telemetry.renderFrameMilliseconds = 2.5; + telemetry.renderFrameBudgetUsedPercent = 15.0; + telemetry.renderFrameMaxMilliseconds = 4.0; + telemetry.readbackQueueMilliseconds = 0.6; + telemetry.completedReadbackCopyMilliseconds = 1.2; + telemetry.completedDrops = 3; + telemetry.acquireMisses = 4; telemetry.shaderBuildsCommitted = 1; const std::filesystem::path root = MakeTestRoot(); @@ -98,6 +105,13 @@ int main() ExpectContains(json, "\"type\":\"color\"", "state JSON should serialize parameter types for the UI"); ExpectContains(json, "\"width\":1920", "state JSON should expose output width"); ExpectContains(json, "\"height\":1080", "state JSON should expose output height"); + ExpectContains(json, "\"renderMs\":2.5", "state JSON should expose top-level render timing"); + ExpectContains(json, "\"budgetUsedPercent\":15", "state JSON should expose top-level render budget percentage"); + ExpectContains(json, "\"renderFrameMs\":2.5", "state JSON should expose cadence render timing"); + ExpectContains(json, "\"readbackQueueMs\":0.6", "state JSON should expose readback queue timing"); + ExpectContains(json, "\"completedReadbackCopyMs\":1.2", "state JSON should expose completed readback copy timing"); + ExpectContains(json, "\"completedDrops\":3", "state JSON should expose completed drop count"); + ExpectContains(json, "\"acquireMisses\":4", "state JSON should expose acquire miss count"); std::filesystem::remove_all(root); diff --git a/tests/RenderCadenceCompositorTelemetryTests.cpp b/tests/RenderCadenceCompositorTelemetryTests.cpp index 31b6579..627833a 100644 --- a/tests/RenderCadenceCompositorTelemetryTests.cpp +++ b/tests/RenderCadenceCompositorTelemetryTests.cpp @@ -26,6 +26,8 @@ struct FakeExchangeMetrics std::size_t scheduledCount = 0; uint64_t completedFrames = 0; uint64_t scheduledFrames = 0; + uint64_t completedDrops = 0; + uint64_t acquireMisses = 0; }; struct FakeExchange @@ -69,6 +71,11 @@ struct FakeRenderThreadMetrics uint64_t skippedFrames = 0; uint64_t shaderBuildsCommitted = 0; uint64_t shaderBuildFailures = 0; + double renderFrameMilliseconds = 0.0; + double renderFrameBudgetUsedPercent = 0.0; + double renderFrameMaxMilliseconds = 0.0; + double readbackQueueMilliseconds = 0.0; + double completedReadbackCopyMilliseconds = 0.0; uint64_t inputFramesReceived = 0; uint64_t inputFramesDropped = 0; uint64_t inputConsumeMisses = 0; @@ -96,6 +103,8 @@ void TestTelemetrySamplesCompletedPollMissesAndShaderCounts() exchange.metrics.scheduledCount = 4; exchange.metrics.completedFrames = 100; exchange.metrics.scheduledFrames = 96; + exchange.metrics.completedDrops = 2; + exchange.metrics.acquireMisses = 3; FakeOutput output; output.metrics.actualBufferedFramesAvailable = true; @@ -110,6 +119,11 @@ void TestTelemetrySamplesCompletedPollMissesAndShaderCounts() renderThread.metrics.skippedFrames = 8; renderThread.metrics.shaderBuildsCommitted = 1; renderThread.metrics.shaderBuildFailures = 0; + renderThread.metrics.renderFrameMilliseconds = 2.5; + renderThread.metrics.renderFrameBudgetUsedPercent = 15.0; + renderThread.metrics.renderFrameMaxMilliseconds = 4.0; + renderThread.metrics.readbackQueueMilliseconds = 0.6; + renderThread.metrics.completedReadbackCopyMilliseconds = 1.2; renderThread.metrics.inputFramesReceived = 9; renderThread.metrics.inputFramesDropped = 2; renderThread.metrics.inputConsumeMisses = 3; @@ -126,10 +140,17 @@ void TestTelemetrySamplesCompletedPollMissesAndShaderCounts() Expect(snapshot.completedFrames == 1, "completed frame count is sampled"); Expect(snapshot.scheduledFrames == 4, "scheduled frame count is sampled"); Expect(snapshot.completedPollMisses == 12, "completed poll misses are sampled"); + Expect(snapshot.completedDrops == 2, "completed drops are sampled"); + Expect(snapshot.acquireMisses == 3, "acquire misses are sampled"); Expect(snapshot.clockOverruns == 5, "clock overrun count is sampled"); Expect(snapshot.clockSkippedFrames == 8, "clock skipped frame count is sampled"); Expect(snapshot.shaderBuildsCommitted == 1, "shader committed count is sampled"); Expect(snapshot.shaderBuildFailures == 0, "shader failure count is sampled"); + Expect(snapshot.renderFrameMilliseconds == 2.5, "render frame timing is sampled"); + Expect(snapshot.renderFrameBudgetUsedPercent == 15.0, "render budget percentage is sampled"); + Expect(snapshot.renderFrameMaxMilliseconds == 4.0, "render frame max timing is sampled"); + Expect(snapshot.readbackQueueMilliseconds == 0.6, "readback queue timing is sampled"); + Expect(snapshot.completedReadbackCopyMilliseconds == 1.2, "completed readback copy timing is sampled"); Expect(snapshot.inputFramesReceived == 9, "input received count is sampled"); Expect(snapshot.inputFramesDropped == 2, "input dropped count is sampled"); Expect(snapshot.inputConsumeMisses == 3, "input consume miss count is sampled"); @@ -179,6 +200,8 @@ void TestTelemetrySerializesToJson() snapshot.scheduledTotal = 118; snapshot.completedPollMisses = 3; snapshot.scheduleFailures = 0; + snapshot.completedDrops = 4; + snapshot.acquireMisses = 5; snapshot.completions = 117; snapshot.displayedLate = 1; snapshot.dropped = 2; @@ -186,6 +209,11 @@ void TestTelemetrySerializesToJson() snapshot.clockSkippedFrames = 5; snapshot.shaderBuildsCommitted = 1; snapshot.shaderBuildFailures = 0; + snapshot.renderFrameMilliseconds = 2.5; + snapshot.renderFrameBudgetUsedPercent = 15.0; + snapshot.renderFrameMaxMilliseconds = 4.0; + snapshot.readbackQueueMilliseconds = 0.6; + snapshot.completedReadbackCopyMilliseconds = 1.2; snapshot.inputFramesReceived = 10; snapshot.inputFramesDropped = 1; snapshot.inputConsumeMisses = 2; @@ -213,10 +241,14 @@ void TestTelemetrySerializesToJson() "\"free\":7,\"completed\":1,\"scheduled\":4," "\"renderedTotal\":120,\"scheduledTotal\":118," "\"completedPollMisses\":3,\"scheduleFailures\":0," + "\"completedDrops\":4,\"acquireMisses\":5," "\"completions\":117,\"late\":1,\"dropped\":2," "\"clockOverruns\":3,\"clockSkippedFrames\":5," "\"clockOveruns\":3,\"clockSkipped\":5," "\"shaderCommitted\":1,\"shaderFailures\":0," + "\"renderFrameMs\":2.5,\"renderFrameBudgetUsedPercent\":15," + "\"renderFrameMaxMs\":4,\"readbackQueueMs\":0.6," + "\"completedReadbackCopyMs\":1.2," "\"inputFramesReceived\":10,\"inputFramesDropped\":1," "\"inputConsumeMisses\":2,\"inputUploadMisses\":3," "\"inputReadyFrames\":1,\"inputReadingFrames\":0,"