Give the draw setup remainder a name instead of a plausible label

Draw setup was 66.7% of the RSX thread, but the bucket only ever held whatever
VKGSRender::begin and end did not charge to a nested scope. Everything with a
body of its own now carries one: the surface write barriers, the render target
on_write pass, the temporary texture release, the mid-draw present check, and
rsx::thread's own prologue and epilogue, which were unscoped on both backends.

Count draws too. A large per-draw bucket is a lot of draws at a fair price or a
few at an unfair one, and those want opposite fixes; the FIFO buckets already
learned that lesson the hard way when a per-packet figure was read per command.

Draw setup keeps the leftovers, which is now the draw clause loop and nothing
that can hide 23 ms.

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;

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
+	// Everything a draw costs before geometry is emitted. The scopes it calls into nest inside
-	// (pipeline, descriptors, texcache_lookup, texture_upload) nest inside and are charged
+	// and are charged to themselves; draw_setup is only ever the remainder. Calling that
-	// to themselves, so what remains here is genuinely per-draw setup and nothing else.
+	// 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) &&
+		if (auto ds = std::get<1>(m_rtts.m_bound_depth_stencil))
-			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.
+			ds->write_barrier(*m_current_command_buffer);
-			// 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
+			if (m_graphics_state.test(rsx::zeta_address_cyclic_barrier) &&
-			invalidate_render_pass();
+				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)
+		for (auto &rtt : m_rtts.m_bound_render_targets)
-	{
-		if (auto surface = std::get<1>(rtt))
 		{
-			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();
 }

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<double>(g_acc.ticks[static_cast<usz>(b)]) * to_ms * 1'000'000.0
+					/ static_cast<double>(g_draw_calls);
+			};
+
+			fmt::append(report, "\n\tdraws           %.0f/frame, %.0f ns each in draw setup",
+				static_cast<double>(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;

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).
 	 *