From 2e303662352af62730969df55ef495562933bf24 Mon Sep 17 00:00:00 2001 From: Hirek193 Date: Sun, 18 Oct 2026 18:41:33 +0200 Subject: [PATCH] Draw the recorded instance draws with the variant seed they were recorded with --- docs/opengl46-renderer.md | 10 +++ gl/query.cpp | 110 ++++++++++++++++++++++++ gl/query.h | 57 ++++++++++++ rendering/opengl46/opengl46renderer.cpp | 46 ++++++++++ rendering/opengl46/opengl46renderer.h | 2 + 5 files changed, 225 insertions(+) diff --git a/docs/opengl46-renderer.md b/docs/opengl46-renderer.md index c7b22543..b579f7ac 100644 --- a/docs/opengl46-renderer.md +++ b/docs/opengl46-renderer.md @@ -405,6 +405,16 @@ editor goes through the first `dynamiclights` headlights, the reflections throug writing to it (`waits`, should stay at 0) and how many times a buffer had to grow (`grown`, a few times after the start). With `gfx.gpucull yes` and `gfx.gpucull.multidraw yes` the `multi draw blocks:` row shows the same for the data of the parts of models drawn with multi draws (one block per draw, written once a frame). +- Shift+F12 shows below `gpu frame total:` the `gpu frame parts:` of the main view: marks of time put one after another + through the frame, so each part lasts until the next one begins and the parts add up to the frame with nothing left out + (`frame setup`, `sun shadows 1` to `3` — 1 the nearest, with the culling of the cascade —, `reflections`, `lamp and + headlight shadows`, `clear, clusters, lights`, `clouds, fog volume`, `sky`, `scene depth` and `contact shadows depth` when + drawn, `colour, opaque` — with the culling, the occlusion depth and the depth prepass of the instances —, + `colour, translucent and cab`, `resolve, ambient occlusion, motion blur`, `exposure, bloom`, `tonemapping, output`, `ui`, + and `other viewports` when there are more of them; only those in the context of the main window are counted). The timings + under `gpu steps:` are measured each from its own pair of marks, and the first mark of a pair can be put while the graphics + card still works on what came before, so a short step right after a heavy one may show some of that work; the parts don't. + Like the other timings, they are of a frame a few frames back. - `gfx.gldebug yes` turns on the OpenGL debug output (`KHR_debug`); messages go to the log. ## Building diff --git a/gl/query.cpp b/gl/query.cpp index 3ee4347c..142f9d53 100644 --- a/gl/query.cpp +++ b/gl/query.cpp @@ -2,6 +2,8 @@ #include "query.h" #include "utilities/Globals.h" +#include + gl::query::query(targets target) : target(target) { @@ -122,3 +124,111 @@ void gl::gpu_timer::collect() m_pending[slot] = false; } } + +gl::gpu_timeline::~gpu_timeline() +{ + for (auto &frame : m_frames) + { + if (frame.queries[0] != 0) + glDeleteQueries(static_cast(frame.queries.size()), frame.queries.data()); + } +} + +void gl::gpu_timeline::begin(char const *Name) +{ + if (m_active) + end(); + + collect(); + auto &frame = m_frames[m_slot]; + m_active = !frame.pending; + if (!m_active) + return; + + if (frame.queries[0] == 0) + glCreateQueries(GL_TIMESTAMP, static_cast(frame.queries.size()), frame.queries.data()); + frame.count = 0; + next(Name); +} + +void gl::gpu_timeline::next(char const *Name) +{ + if (!m_active) + return; + + auto &frame = m_frames[m_slot]; + // the last mark is kept for end(); past the limit the part under way goes on + if (frame.count + 1 >= MARKS) + return; + + glQueryCounter(frame.queries[frame.count], GL_TIMESTAMP); + frame.names[frame.count] = Name; + ++frame.count; +} + +void gl::gpu_timeline::end() +{ + if (!m_active) + return; + + auto &frame = m_frames[m_slot]; + glQueryCounter(frame.queries[frame.count], GL_TIMESTAMP); + frame.names[frame.count] = nullptr; + ++frame.count; + frame.pending = true; + m_slot = (m_slot + 1) % SLOTS; + m_active = false; +} + +std::vector const &gl::gpu_timeline::result() +{ + collect(); + return m_last; +} + +void gl::gpu_timeline::collect() +{ + // frames finish in the order they were issued, oldest first + for (size_t i = 0; i < SLOTS; ++i) + { + auto &frame = m_frames[(m_slot + i) % SLOTS]; + if (!frame.pending) + continue; + + auto ready = true; + for (size_t mark = 0; (mark < frame.count) && ready; ++mark) + { + GLint available = GL_FALSE; + glGetQueryObjectiv(frame.queries[mark], GL_QUERY_RESULT_AVAILABLE, &available); + ready = (available != GL_FALSE); + } + if (!ready) + break; + + m_last.clear(); + GLuint64 first = 0; + GLuint64 previous = 0; + for (size_t mark = 0; mark < frame.count; ++mark) + { + GLuint64 time = 0; + glGetQueryObjectui64v(frame.queries[mark], GL_QUERY_RESULT, &time); + if (mark == 0) + first = time; + else + { + auto const length = (time >= previous ? time - previous : 0); + auto const *name = frame.names[mark - 1]; + auto lookup = m_last.begin(); + while ((lookup != m_last.end()) && (std::strcmp(lookup->name, name) != 0)) + ++lookup; + if (lookup != m_last.end()) + lookup->time += length; + else + m_last.push_back({name, length}); + } + previous = time; + } + m_total = (previous >= first ? previous - first : 0); + frame.pending = false; + } +} diff --git a/gl/query.h b/gl/query.h index 4960c272..a1318d11 100644 --- a/gl/query.h +++ b/gl/query.h @@ -2,6 +2,7 @@ #include #include +#include #include "object.h" @@ -65,4 +66,60 @@ class gpu_timer bool m_active = false; std::optional m_last; }; + +// gpu time of the parts of a frame, from GL_TIMESTAMP queries put one after another: a part lasts from its mark to the next +// one, so the parts add up to the time from the first mark to the last, with nothing left out and nothing counted twice. +// the first mark of a gpu_timer is put while the gpu may still be busy with what came before, so its time can hold the tail +// of that work; in the run of marks that time goes to the part it belongs to. results are read a few frames later without +// stalling; if the gpu falls further behind, the frame is skipped +class gpu_timeline +{ + public: + struct part + { + char const *name; + uint64_t time; // nanoseconds + }; + + gpu_timeline() = default; + ~gpu_timeline(); + gpu_timeline(const gpu_timeline &) = delete; + gpu_timeline &operator=(const gpu_timeline &) = delete; + + // starts the frame with its first part. the names are kept as pointers: string literals + void begin(char const *Name); + // ends the part under way and starts the next one + void next(char const *Name); + void end(); + bool active() const + { + return m_active; + } + // parts of the most recent finished frame in the order they came first, the time of parts of the same name added up + std::vector const &result(); + // from the first mark of that frame to the last + uint64_t total() const + { + return m_total; + } + + private: + void collect(); + + static constexpr size_t SLOTS = 4; + static constexpr size_t MARKS = 32; // per frame, the last one included + struct frame + { + std::array queries{}; + std::array names{}; + size_t count = 0; // marks put + bool pending = false; + }; + std::array m_frames; + // slot written by the next begin(), also the oldest one still pending + size_t m_slot = 0; + bool m_active = false; + std::vector m_last; + uint64_t m_total = 0; +}; } diff --git a/rendering/opengl46/opengl46renderer.cpp b/rendering/opengl46/opengl46renderer.cpp index c0acd626..b26c52dc 100644 --- a/rendering/opengl46/opengl46renderer.cpp +++ b/rendering/opengl46/opengl46renderer.cpp @@ -652,6 +652,8 @@ bool opengl46_renderer::Render() m_gllasttime = *result; m_timequery->begin(); } + // the context of the main view is current here, the one of the previous frame's end + m_gputimeline.begin("frame setup"); // fetch simulation data if (simulation::is_ready) @@ -729,6 +731,7 @@ bool opengl46_renderer::Render() gl::framebuffer::unbind(); m_current_viewport = &(*m_viewports.front()); + m_gputimeline.end(); /* m_debugtimestext += "cpu: " + to_string(Timer::subsystem.gfx_color.average(), 2) + " ms (" + std::to_string(m_cellqueue.size()) + " sectors)\n" += "cpu swap: " + to_string(Timer::subsystem.gfx_swap.average(), 2) + " ms\n" += "uilayer: " + to_string(Timer::subsystem.gfx_gui.average(), 2) + "ms\n" += @@ -780,6 +783,15 @@ void opengl46_renderer::SwapBuffers() m_debugtimestext += " swap: " + to_string( Timer::subsystem.gfx_swap.average(), 2 ) + " ms\n"; if (m_gllasttime) m_debugtimestext += "gpu frame total: " + to_string((double)(m_gllasttime / 1000ULL) / 1000.0, 3) + " ms\n"; + // the parts follow one another and add up to the frame; the steps below are timed each on its own and can hold the tail + // of the work before them + if( auto const &gpuparts { m_gputimeline.result() }; false == gpuparts.empty() ) { + m_debugtimestext += "gpu frame parts: " + to_string( static_cast( m_gputimeline.total() ) / 1000000.0, 3 ) + " ms\n"; + for( auto const &part : gpuparts ) { + m_debugtimestext += " " + std::string{ part.name } + ": " + to_string( static_cast( part.time ) / 1000000.0, 3 ) + " ms\n"; + } + m_debugtimestext += "gpu steps:\n"; + } if (auto const clusterstime = m_clusterstimer.result()) m_debugtimestext += " clusters: " + to_string(static_cast(*clusterstime) / 1000000.0, 3) + " ms\n"; if (auto const culltime = m_cullstimer.result()) @@ -1063,6 +1075,11 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) } m_colorpass = m_renderpass; // cache pass data + // parts of the gpu time of the frame; the marks go through the main view only, in the context they were begun in + auto const gpupart = [this, &vp](char const *Name) { + if (vp.main) + m_gputimeline.next(Name); + }; scene_ubs.time = Timer::GetTime(); { @@ -1135,6 +1152,7 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) if (Global.gfx_envmap_enabled && vp.main) { + gpupart("reflections"); // potentially update environmental cube map m_renderpass.draw_stats = {}; Timer::subsystem.gfx_reflections.start(); @@ -1149,11 +1167,13 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) if (vp.main) { + gpupart("lamp and headlight shadows"); Render_local_shadows(); Render_lamp_shadows(); Render_headlight_shadows(); } + gpupart("clear, clusters, lights"); glClearColor(0.0f, 0.0f, 0.0f, 0.0f); setup_drawing(false); @@ -1231,6 +1251,7 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) } // the clouds of the view and the fog volume, which take the lights of the clusters and the shadow map of the pass + gpupart("clouds, fog volume"); { auto const fogtarget{ Global.gfx_skippipeline ? target_size : glm::ivec2{ vp.width, vp.height } }; if( vp.main ) { @@ -1244,6 +1265,7 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) } glDebug("render environment"); + gpupart("sky"); scene_ubs.projection = OpenGLMatrices.data(GL_PROJECTION); // back to the rotation of the camera after the faces of the environment map, which are drawn with their own @@ -1261,14 +1283,19 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) if ((Global.gfx_depthprepass_scene || contactshadows) && vp.main && (false == Global.bWireFrame)) { glDebug("render scene depth"); + gpupart("scene depth"); Render_Scene_Depth(future); if (contactshadows) + { + gpupart("contact shadows depth"); Setup_Contact_Shadows(vp); + } } if (vp.main) m_contactshadowslast = m_contactshadows; // opaque parts... + gpupart("colour, opaque"); setup_drawing(false); // without rain/snow we can render the cab early to limit the overdraw @@ -1299,6 +1326,7 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) // ...translucent parts glDebug("render translucent region"); + gpupart("colour, translucent and cab"); setup_drawing(true); Render_Alpha(simulation::Region); Render_editor_overlay(); @@ -1359,6 +1387,7 @@ void opengl46_renderer::Render_pass(viewport_config &vp, rendermode const Mode) if (!Global.gfx_skippipeline) { + gpupart("resolve, ambient occlusion, motion blur"); // the targets of the ambient occlusion are there only when it was on at the start auto const aomode{(vp.ssao_tex != nullptr) ? Global.gfx_postfx_ao : 0}; if (Global.gfx_postfx_motionblur_enabled) @@ -1389,6 +1418,7 @@ if (!Global.gfx_skippipeline) } } + gpupart("exposure, bloom"); // the exposure follows the main view; the other viewports use it too if (Global.gfx_postfx_autoexposure && vp.main) m_exposure.measure(*vp.main2_tex, Timer::GetDeltaRenderTime()); @@ -1407,6 +1437,7 @@ if (!Global.gfx_skippipeline) if (bloomtexture != nullptr) tonemapinput.push_back(bloomtexture); + gpupart("tonemapping, output"); if (!Global.gfx_shadergamma) glEnable(GL_FRAMEBUFFER_SRGB); @@ -1459,6 +1490,7 @@ if (!Global.gfx_skippipeline) glDisable(GL_FRAMEBUFFER_SRGB); glDebug("uilayer render"); + gpupart("ui"); Timer::subsystem.gfx_gui.start(); if (vp.main) { @@ -1470,6 +1502,10 @@ if (!Global.gfx_skippipeline) Timer::subsystem.gfx_gui.stop(); + // viewports drawn after this one in the same context (vr) land in the last part; others aren't measured + if (m_viewports.size() > 1) + gpupart("other viewports"); + // restore binding scene_ubo->bind_uniform(); @@ -1502,6 +1538,11 @@ if (!Global.gfx_skippipeline) for( auto idx = 0; idx < m_shadowpass.size(); ++idx ) { + // the pass is drawn for the main view only + static char const *const gpuparts[] = { "sun shadows 1", "sun shadows 2", "sun shadows 3" }; + static_assert( std::size( gpuparts ) == std::tuple_size_v ); + m_gputimeline.next( gpuparts[ idx ] ); + m_shadow_fb->attach( *m_shadow_tex, GL_DEPTH_ATTACHMENT, idx ); m_shadow_fb->clear( GL_DEPTH_BUFFER_BIT ); @@ -4195,6 +4236,9 @@ opengl46_renderer::indirect_counts opengl46_renderer::Render_Instances_Indirect_ opengl46_renderer::indirect_counts opengl46_renderer::Render_Instances_Indirect_Depth( opengl46_instance_cull::command_set const Set ) { + // the draws were recorded with the seed of scenery models and sleepers, 0 (TAnimModel::RaPrepare()); vehicles drawn since + // leave their own, which would pick other texture variants than those the draws were recorded and ordered with + TSubModel::iVariantSeed = 0; indirect_counts counts; auto const count { m_indirectdraws.size() }; // whether the prepass of the class draws the draw, and with which diffuse texture (class 2) @@ -4283,6 +4327,8 @@ opengl46_renderer::indirect_counts opengl46_renderer::Render_Instances_Indirect_ opengl46_renderer::indirect_counts opengl46_renderer::Render_Instances_Indirect_Colour( opengl46_instance_cull::command_set const Set ) { + // as in Render_Instances_Indirect_Depth(): the seed the draws were recorded with + TSubModel::iVariantSeed = 0; indirect_counts counts; auto const count { m_indirectdraws.size() }; for( std::size_t index = 0; index < count; ) { diff --git a/rendering/opengl46/opengl46renderer.h b/rendering/opengl46/opengl46renderer.h index 5f504c2b..7333a1ef 100644 --- a/rendering/opengl46/opengl46renderer.h +++ b/rendering/opengl46/opengl46renderer.h @@ -702,6 +702,8 @@ class opengl46_renderer : public gfx_renderer { std::optional m_timequery; GLuint64 m_gllasttime = 0; + // gpu time of the parts of the frame, marks put one after another through the main view (the context of m_window) + gl::gpu_timeline m_gputimeline; // gpu time of the light cluster compute passes; the debug panel shows it once a pass measures it gl::gpu_timer m_clusterstimer; // gpu time of assigning the lights to the clusters, done every frame