Never make the client wait for drawing, or hold up its steps

The renderer process now takes each view's chunks on a thread of its own as
they come, and draws the newest frame on its main thread: the client no longer
waits for the previous frame to be drawn (on a VM, 22 of a frame's 25 ms).

The adapter records the client's steps (SceneViewer::step, by replacing its
entry in the exported IFrameListener vtable, after checking it), and the frame
pacer doesn't ask for a frame that wouldn't end before the next step is due: a
late step made the client catch up two at once, which showed as hitches. While
the renderer process covers the view, the client's renderer doesn't begin or
present frames, which could wait for the display.

The engine's stats now include the time in the client renderer's methods.

Co-Authored-By: Claude Opus 5.5 <[email protected]>

adapter/engine.cpp

@@ -8,6 +8,7 @@
 #include <vector>
 
 #include "frame_pacer.hpp"
+#include "inner_timing.hpp"
 #include "log.hpp"
 #include "resources.hpp"
 
@@ -31,7 +32,7 @@ protocol::SetTransform transform_command(const imvu::Transform& t)
 } // namespace
 
 Engine::Engine(imvu::SharedPtr<imvu::PiRenderEngine> inner, std::shared_ptr<Recorder> recorder, HWND window)
-    : inner_(std::move(inner)), recorder_(std::move(recorder)), window_(window)
+    : inner_(std::move(inner)), recorder_(std::move(recorder)), window_(window), innerTicksAtStats_(innerTicks)
 {
     QueryPerformanceCounter(&statsStart_);
     if (window_ != nullptr) {
@@ -52,21 +53,21 @@ void Engine::setState(State state, std::uint32_t value)
     recorder_->add(Op::SetState, protocol::SetState{state, value});
 }
 
-void Engine::resizeFrameBuffer(imvu::Vec2i size) { inner_->resizeFrameBuffer(size); }
+void Engine::resizeFrameBuffer(imvu::Vec2i size) { const InnerCall timed; inner_->resizeFrameBuffer(size); }
 
-void Engine::enable2dFrameBuffer() { inner_->enable2dFrameBuffer(); }
+void Engine::enable2dFrameBuffer() { const InnerCall timed; inner_->enable2dFrameBuffer(); }
 
 void Engine::clear(std::uint32_t flags, imvu::Color color)
 {
     if (innerDraws()) {
-        inner_->clear(flags, color);
+        { const InnerCall timed; inner_->clear(flags, color); }
     }
     recorder_->add(Op::Clear, protocol::Clear{flags, color});
 }
 
 void Engine::setProjection(imvu::Vec2i viewport, const imvu::Mat4f& projection)
 {
-    inner_->setProjection(viewport, projection);
+    { const InnerCall timed; inner_->setProjection(viewport, projection); }
     if (projection.m[2][3] == 0.0f) {
         ++stats_.flat;
     }
@@ -77,19 +78,19 @@ void Engine::setProjection(imvu::Vec2i viewport, const imvu::Mat4f& projection)
 
 void Engine::setModelSpace(const imvu::Transform& model)
 {
-    inner_->setModelSpace(model);
+    { const InnerCall timed; inner_->setModelSpace(model); }
     recorder_->add(Op::SetModel, transform_command(model));
 }
 
 void Engine::setViewSpace(const imvu::Transform& view)
 {
-    inner_->setViewSpace(view);
+    { const InnerCall timed; inner_->setViewSpace(view); }
     recorder_->add(Op::SetView, transform_command(view));
 }
 
 void Engine::setTextures(imvu::PiRenderTexture* texture0, imvu::PiRenderTexture* texture1)
 {
-    inner_->setTextures(inner(texture0), inner(texture1));
+    { const InnerCall timed; inner_->setTextures(inner(texture0), inner(texture1)); }
     for (imvu::PiRenderTexture* texture : {texture0, texture1}) {
         if (texture != nullptr && id(texture) == 0 && foreignLogged_ < 20) {
             ++foreignLogged_;
@@ -101,61 +102,61 @@ void Engine::setTextures(imvu::PiRenderTexture* texture0, imvu::PiRenderTexture*
 
 void Engine::setDepthTestingOn(bool on)
 {
-    inner_->setDepthTestingOn(on);
+    { const InnerCall timed; inner_->setDepthTestingOn(on); }
     setState(State::DepthTest, on);
 }
 
 void Engine::setDepthWritingOn(bool on)
 {
-    inner_->setDepthWritingOn(on);
+    { const InnerCall timed; inner_->setDepthWritingOn(on); }
     setState(State::DepthWrite, on);
 }
 
 void Engine::setBlendMode(imvu::RenderBlendMode mode)
 {
-    inner_->setBlendMode(mode);
+    { const InnerCall timed; inner_->setBlendMode(mode); }
     setState(State::BlendMode, static_cast<std::uint32_t>(mode));
 }
 
 void Engine::setAlphaTestingOn(bool on)
 {
-    inner_->setAlphaTestingOn(on);
+    { const InnerCall timed; inner_->setAlphaTestingOn(on); }
     setState(State::AlphaTest, on);
 }
 
 void Engine::setAlphaTestValue(float value)
 {
-    inner_->setAlphaTestValue(value);
+    { const InnerCall timed; inner_->setAlphaTestValue(value); }
     setState(State::AlphaReference, static_cast<std::uint32_t>(std::lround(value * 255.0f)));
 }
 
 void Engine::setBlendingOn(bool on)
 {
-    inner_->setBlendingOn(on);
+    { const InnerCall timed; inner_->setBlendingOn(on); }
     setState(State::Blending, on);
 }
 
 void Engine::setBackFaceCullingOn(bool on)
 {
-    inner_->setBackFaceCullingOn(on);
+    { const InnerCall timed; inner_->setBackFaceCullingOn(on); }
     setState(State::Culling, on);
 }
 
 void Engine::setNormalInvertingOn(bool on)
 {
-    inner_->setNormalInvertingOn(on);
+    { const InnerCall timed; inner_->setNormalInvertingOn(on); }
     setState(State::NormalInverting, on);
 }
 
 void Engine::setLightingOn(bool on)
 {
-    inner_->setLightingOn(on);
+    { const InnerCall timed; inner_->setLightingOn(on); }
     setState(State::Lighting, on);
 }
 
 void Engine::setLightProperties(std::uint32_t index, const imvu::LightProperties& light)
 {
-    inner_->setLightProperties(index, light);
+    { const InnerCall timed; inner_->setLightProperties(index, light); }
     protocol::SetLight command{index, light.enabled, light.diffuse,
                                light.type == imvu::LightType::Directional,
                                {light.vector.x, light.vector.y, light.vector.z}};
@@ -168,25 +169,25 @@ void Engine::setLightProperties(std::uint32_t index, const imvu::LightProperties
 
 void Engine::setFogOn(bool on)
 {
-    inner_->setFogOn(on);
+    { const InnerCall timed; inner_->setFogOn(on); }
     setState(State::Fog, on);
 }
 
 void Engine::setFogAttributes(float start, float end, imvu::Color color)
 {
-    inner_->setFogAttributes(start, end, color);
+    { const InnerCall timed; inner_->setFogAttributes(start, end, color); }
     recorder_->add(Op::SetFog, protocol::SetFog{start, end, color});
 }
 
 void Engine::setTextureTransformMatrixIdentity(std::uint32_t stage)
 {
-    inner_->setTextureTransformMatrixIdentity(stage);
+    { const InnerCall timed; inner_->setTextureTransformMatrixIdentity(stage); }
     recorder_->add(Op::SetTextureTransform, protocol::SetTextureTransform{stage, 1, {1, 0, 0, 1, 0, 0}});
 }
 
 void Engine::setTextureTransformMatrix(std::uint32_t stage, const imvu::TextureTransform& transform)
 {
-    inner_->setTextureTransformMatrix(stage, transform);
+    { const InnerCall timed; inner_->setTextureTransformMatrix(stage, transform); }
     protocol::SetTextureTransform command{stage, 0, {}};
     std::memcpy(command.m, transform.m, sizeof(command.m));
     recorder_->add(Op::SetTextureTransform, command);
@@ -194,7 +195,7 @@ void Engine::setTextureTransformMatrix(std::uint32_t stage, const imvu::TextureT
 
 void Engine::setEnvironmentAmbient(imvu::Color color)
 {
-    inner_->setEnvironmentAmbient(color);
+    { const InnerCall timed; inner_->setEnvironmentAmbient(color); }
     setState(State::Ambient, color);
 }
 
@@ -264,12 +265,15 @@ void Engine::beginRendering(imvu::PiRenderTarget* target)
     windowFrame_ = target == nullptr;
     // Frames into our render targets are drawn by the renderer process only; the client's renderer doesn't know them.
     ourTarget_ = ours(target) ? target : nullptr;
-    if (ourTarget_ == nullptr) {
-        inner_->beginRendering(target);
-    }
     // Decided per frame: frames into the client renderer's render targets, and frames while the renderer process
     // doesn't cover the view, are drawn by the client's renderer.
     const bool takenOver = ourTarget_ != nullptr || (target == nullptr && recorder_->covering());
+    // Frames the client's renderer doesn't draw aren't begun in it either: its endRendering presents, which can wait
+    // for the display (and would show nothing: the renderer process's window covers it).
+    innerFrame_ = !takenOver;
+    if (innerFrame_) {
+        { const InnerCall timed; inner_->beginRendering(target); }
+    }
     if (takenOver != takenOver_ && target == nullptr) {
         log::info("engine: frame {}: {}", frames_, takenOver ? "drawn by the renderer process" : "drawn by the client's renderer");
     }
@@ -290,8 +294,8 @@ void Engine::beginRendering(imvu::PiRenderTarget* target)
 
 void Engine::endRendering()
 {
-    if (ourTarget_ == nullptr) {
-        inner_->endRendering();
+    if (innerFrame_) {
+        { const InnerCall timed; inner_->endRendering(); }
     }
     LARGE_INTEGER now;
     QueryPerformanceCounter(&now);
@@ -321,16 +325,19 @@ void Engine::endRendering()
         if (statsLogged_ < 6 || frames_ % 3000 == 0) {
             ++statsLogged_;
             log::info("engine: last 300 frames: {:.0f} per second; each {:.2f} ms beginRendering to endRendering, {:.2f} ms "
-                      "of it sending, {:.0f} KB sent, {:.1f} buffer updates ({:.0f} KB); drawTriangles {} (and {} with "
-                      "buffers not ours), drawTrianglesFromMemory {} (and {} without indices), point sprites {}, lines {}, "
-                      "2D projections {}",
-                      300 / seconds, frameSeconds_ * 1000 / 300, sent.sendSeconds * 1000 / 300,
+                      "in the client renderer's methods, {:.2f} ms sending, {:.0f} KB sent, {:.1f} buffer updates ({:.0f} "
+                      "KB); drawTriangles {} (and {} with buffers not ours), drawTrianglesFromMemory {} (and {} without "
+                      "indices), point sprites {}, lines {}, 2D projections {}",
+                      300 / seconds, frameSeconds_ * 1000 / 300,
+                      static_cast<double>(innerTicks - innerTicksAtStats_) * 1000 / static_cast<double>(frequency.QuadPart) / 300,
+                      sent.sendSeconds * 1000 / 300,
                       static_cast<double>(sent.bytes) / 1024 / 300, sent.bufferUpdates / 300.0,
                       static_cast<double>(sent.bufferBytes) / 1024 / 300, stats_.triangles, stats_.foreignTriangles,
                       stats_.indexed, stats_.unindexed, stats_.sprites, stats_.lines, stats_.flat);
         }
         stats_ = {};
         frameSeconds_ = 0;
+        innerTicksAtStats_ = innerTicks;
     }
 }
 
@@ -339,7 +346,7 @@ void Engine::drawTriangles(imvu::PiInternalIndexBuffer* indices, imvu::PiInterna
                            imvu::PiInternalVertexBuffer* colors)
 {
     if (innerDraws()) {
-        inner_->drawTriangles(inner(indices), inner(positions), inner(normals), inner(texCoords), inner(colors));
+        { const InnerCall timed; inner_->drawTriangles(inner(indices), inner(positions), inner(normals), inner(texCoords), inner(colors)); }
     }
     ++(id(indices) != 0 && id(positions) != 0 ? stats_.triangles : stats_.foreignTriangles);
     recorder_->add(Op::DrawTriangles,
@@ -349,7 +356,7 @@ void Engine::drawTriangles(imvu::PiInternalIndexBuffer* indices, imvu::PiInterna
 void Engine::drawLine(imvu::Vec3f from, imvu::Vec3f to, imvu::Color color)
 {
     if (innerDraws()) {
-        inner_->drawLine(from, to, color);
+        { const InnerCall timed; inner_->drawLine(from, to, color); }
     }
     ++stats_.lines;
 }
@@ -357,7 +364,7 @@ void Engine::drawLine(imvu::Vec3f from, imvu::Vec3f to, imvu::Color color)
 void Engine::drawPointSprites(const imvu::PointSpriteVector& sprites)
 {
     if (innerDraws()) {
-        inner_->drawPointSprites(sprites);
+        { const InnerCall timed; inner_->drawPointSprites(sprites); }
     }
     ++stats_.sprites;
     if (sprites.first == nullptr || sprites.last <= sprites.first) {
@@ -378,7 +385,7 @@ void Engine::drawTrianglesFromMemory(std::uint32_t vertexCount, std::uint32_t in
                                      const imvu::VertexAttributeArray<imvu::Color>& colors)
 {
     if (innerDraws()) {
-        inner_->drawTrianglesFromMemory(vertexCount, indexCount, indices, positions, normals, texCoords, colors);
+        { const InnerCall timed; inner_->drawTrianglesFromMemory(vertexCount, indexCount, indices, positions, normals, texCoords, colors); }
     }
     ++(indices != nullptr ? stats_.indexed : stats_.unindexed);
     if (positions.data == nullptr || vertexCount == 0) {