diff --git a/rpcs3/Emu/RSX/RSXThread.cpp b/rpcs3/Emu/RSX/RSXThread.cpp index b7e30e110..33d4bdbd6 100644 --- a/rpcs3/Emu/RSX/RSXThread.cpp +++ b/rpcs3/Emu/RSX/RSXThread.cpp @@ -777,6 +777,11 @@ namespace rsx void thread::begin() { + // Backend-independent draw prologue. The read_barrier below is a hard sync on the + // software conditional render path, so this is not always the trivial flag work it + // looks like, and unscoped it was billed to draw_setup along with everything else. + RSX_PROF_SCOPE(draw_prologue); + if (cond_render_ctrl.hw_cond_active) { if (!cond_render_ctrl.eval_pending()) @@ -824,6 +829,10 @@ namespace rsx void thread::end() { + // Backend-independent draw epilogue: clause cleanup, push buffer teardown and the + // ZCULL draw hook, all of which scale with draw count rather than with frame count. + RSX_PROF_SCOPE(draw_epilogue); + if (capture_current_frame) { capture::capture_draw_memory(this); @@ -832,6 +841,10 @@ namespace rsx in_begin_end = false; m_frame_stats.draw_calls++; + // Counted here rather than at the backend call sites so every early return in + // VKGSRender::end is included; all of them route through this function. + if (rsx::prof::enabled()) [[unlikely]] rsx::prof::g_draw_calls++; + method_registers.current_draw_clause.post_execute_cleanup(m_ctx); m_graphics_state |= rsx::pipeline_state::framebuffer_reads_dirty; diff --git a/rpcs3/Emu/RSX/VK/VKDraw.cpp b/rpcs3/Emu/RSX/VK/VKDraw.cpp index 4ca9b56b2..d13524f2e 100644 --- a/rpcs3/Emu/RSX/VK/VKDraw.cpp +++ b/rpcs3/Emu/RSX/VK/VKDraw.cpp @@ -1214,9 +1214,10 @@ void VKGSRender::emit_geometry(u32 sub_index) void VKGSRender::begin() { - // Everything a draw costs before geometry is emitted. The scopes it calls into - // (pipeline, descriptors, texcache_lookup, texture_upload) nest inside and are charged - // to themselves, so what remains here is genuinely per-draw setup and nothing else. + // Everything a draw costs before geometry is emitted. The scopes it calls into nest inside + // and are charged to themselves; draw_setup is only ever the remainder. Calling that + // remainder "setup" hid 23 ms/frame of barriers and epilogue work behind a plausible name, + // so every block with a body of its own now carries a scope and this keeps the leftovers. RSX_PROF_SCOPE(draw_setup); // Save shader state now before prefetch and loading happens @@ -1261,6 +1262,8 @@ void VKGSRender::end() // Check for frame resource status here because it is possible for an async flip to happen between begin/end if (m_current_frame->flags & frame_context_state::dirty) [[unlikely]] { + RSX_PROF_SCOPE(present_check); + check_present_status(); if (m_current_frame->swap_command_buffer) [[unlikely]] @@ -1297,32 +1300,38 @@ void VKGSRender::end() m_frame_stats.setup_time += m_profiler.duration(); // Apply write memory barriers - if (auto ds = std::get<1>(m_rtts.m_bound_depth_stencil)) { - ds->write_barrier(*m_current_command_buffer); + // Each write_barrier can resolve, copy or tear down the render pass, which on a tiler + // is the most expensive thing available. Unscoped it read as flat per-draw setup cost. + RSX_PROF_SCOPE(wr_barrier); - if (m_graphics_state.test(rsx::zeta_address_cyclic_barrier) && - ds->current_layout != VK_IMAGE_LAYOUT_DEPTH_STENCIL_ATTACHMENT_OPTIMAL) + if (auto ds = std::get<1>(m_rtts.m_bound_depth_stencil)) { - // We actually need to end the subpass as a minimum. Without this, early-Z optimiazations in following draws will clobber reads from previous draws and cause flickering. - // Since we're ending the subpass, might as well restore DCC/HiZ for extra performance - ds->change_layout(*m_current_command_buffer, VK_IMAGE_LAYOUT_DEPTH_STENCIL_ATTACHMENT_OPTIMAL); - ds->reset_surface_counters(); + ds->write_barrier(*m_current_command_buffer); - // Regenerate render pass key - invalidate_render_pass(); + if (m_graphics_state.test(rsx::zeta_address_cyclic_barrier) && + ds->current_layout != VK_IMAGE_LAYOUT_DEPTH_STENCIL_ATTACHMENT_OPTIMAL) + { + // We actually need to end the subpass as a minimum. Without this, early-Z optimiazations in following draws will clobber reads from previous draws and cause flickering. + // Since we're ending the subpass, might as well restore DCC/HiZ for extra performance + ds->change_layout(*m_current_command_buffer, VK_IMAGE_LAYOUT_DEPTH_STENCIL_ATTACHMENT_OPTIMAL); + ds->reset_surface_counters(); + + // Regenerate render pass key + invalidate_render_pass(); + } } - } - for (auto &rtt : m_rtts.m_bound_render_targets) - { - if (auto surface = std::get<1>(rtt)) + for (auto &rtt : m_rtts.m_bound_render_targets) { - surface->write_barrier(*m_current_command_buffer); + if (auto surface = std::get<1>(rtt)) + { + surface->write_barrier(*m_current_command_buffer); + } } - } - m_graphics_state.clear(rsx::zeta_address_cyclic_barrier); + m_graphics_state.clear(rsx::zeta_address_cyclic_barrier); + } m_frame_stats.setup_time += m_profiler.duration(); @@ -1359,7 +1368,11 @@ void VKGSRender::end() } } - m_texture_cache.release_uncached_temporary_subresources(); + { + RSX_PROF_SCOPE(tex_release); + m_texture_cache.release_uncached_temporary_subresources(); + } + m_frame_stats.textures_upload_time += m_profiler.duration(); u32 sub_index = 0; // RSX subdraw ID @@ -1390,7 +1403,12 @@ void VKGSRender::end() m_current_command_buffer->flags &= ~(vk::command_buffer::cb_has_conditional_render); } - m_rtts.on_write(m_framebuffer_layout.color_write_enabled, m_framebuffer_layout.zeta_write_enabled); + { + // Touches every bound surface and can queue cache invalidations, so it is per-draw + // work in the same class as the write barriers rather than bookkeeping. + RSX_PROF_SCOPE(rtt_write); + m_rtts.on_write(m_framebuffer_layout.color_write_enabled, m_framebuffer_layout.zeta_write_enabled); + } rsx::thread::end(); } diff --git a/rpcs3/Emu/RSX/rsx_profiler.cpp b/rpcs3/Emu/RSX/rsx_profiler.cpp index 19b5935fe..63ee54dca 100644 --- a/rpcs3/Emu/RSX/rsx_profiler.cpp +++ b/rpcs3/Emu/RSX/rsx_profiler.cpp @@ -20,6 +20,7 @@ namespace rsx::prof u64 g_fifo_refills = 0; u64 g_fifo_commands = 0; u64 g_fifo_dispatches = 0; + u64 g_draw_calls = 0; u32 g_method_counts[method_slot_count] = {}; u64 g_fifo_refill_bytes = 0; u64 g_fifo_refill_stalls = 0; @@ -85,6 +86,12 @@ namespace rsx::prof { case bucket::fifo_decode: return "FIFO decode"; case bucket::draw_setup: return "Draw setup"; + case bucket::draw_prologue: return "Draw prologue"; + case bucket::draw_epilogue: return "Draw epilogue"; + case bucket::wr_barrier: return "Write barrier"; + case bucket::rtt_write: return "RTT on_write"; + case bucket::tex_release: return "Temp tex release"; + case bucket::present_check: return "Present check"; case bucket::vertex: return "Vertex/index"; case bucket::shader_translate: return "Shader translate"; case bucket::shader_compile: return "Shader compile"; @@ -272,6 +279,29 @@ namespace rsx::prof } } + if (g_draw_calls) + { + // Every bucket named here is entered exactly once per draw, so dividing by the + // draw count turns "this bucket is big" into "each draw pays this much", which is + // the form that says whether to cut the per-draw cost or the number of draws. + const auto ns_per_draw = [&](bucket b) + { + return static_cast(g_acc.ticks[static_cast(b)]) * to_ms * 1'000'000.0 + / static_cast(g_draw_calls); + }; + + fmt::append(report, "\n\tdraws %.0f/frame, %.0f ns each in draw setup", + static_cast(g_draw_calls) / frames, + ns_per_draw(bucket::draw_setup)); + + fmt::append(report, "\n\tper draw prologue %.0f, epilogue %.0f, wr barrier %.0f, on_write %.0f, tex release %.0f ns", + ns_per_draw(bucket::draw_prologue), + ns_per_draw(bucket::draw_epilogue), + ns_per_draw(bucket::wr_barrier), + ns_per_draw(bucket::rtt_write), + ns_per_draw(bucket::tex_release)); + } + { // Top methods by volume. Names via gcm_printing, which is the same table the // command dumps use, so these read the same as the log's own FIFO traces. @@ -306,6 +336,7 @@ namespace rsx::prof g_fifo_commands = 0; g_fifo_dispatches = 0; + g_draw_calls = 0; std::fill(std::begin(g_method_counts), std::end(g_method_counts), 0u); g_fifo_refills = 0; g_fifo_refill_bytes = 0; diff --git a/rpcs3/Emu/RSX/rsx_profiler.h b/rpcs3/Emu/RSX/rsx_profiler.h index 47a33e830..8d699ed89 100644 --- a/rpcs3/Emu/RSX/rsx_profiler.h +++ b/rpcs3/Emu/RSX/rsx_profiler.h @@ -33,7 +33,13 @@ namespace rsx::prof enum class bucket : u8 { fifo_decode, // Reading and dispatching FIFO commands - draw_setup, // Draw clause setup and state validation + draw_setup, // Draw clause iteration glue left over once the scopes below are charged + draw_prologue, // rsx::thread::begin: conditional render eval and draw mode classify + draw_epilogue, // rsx::thread::end: clause cleanup, push buffers, ZCULL on_draw + wr_barrier, // Depth/colour surface write barriers issued before binding resources + rtt_write, // Render target on_write bookkeeping after the draw is recorded + tex_release, // Releasing uncached temporary texture subresources + present_check, // Mid-draw present status check when the frame context went dirty vertex, // Vertex and index processing, including layout conversion shader_translate, // RSX shader decompilation to GLSL/SPIR-V shader_compile, // Host driver compiling the translated shader @@ -198,6 +204,15 @@ namespace rsx::prof */ extern u64 g_fifo_dispatches; + /** + * Draws that reached rsx::thread::end, so the per-draw buckets can be priced. + * + * Draw setup being the largest bucket says nothing on its own: a lot of draws at a sane + * cost each and a few at an insane one are the same number and want opposite fixes. This + * is the denominator that tells them apart, the same way g_fifo_dispatches did for decode. + */ + extern u64 g_draw_calls; + /** * Commands seen per RSX method register, indexed by (id >> 2). *