Rank method handlers by cost instead of by volume

The handler bodies are 60% of the RSX thread in Arkham City and the dispatch
machinery around them is 3.5%, so the question is which handlers. The method
histogram cannot answer it: it counts calls, and the busiest method may be a
register write while a rare one does the work.

Keep the interval the dispatch site already measures. It brackets the call with
two counter reads to fill the method_call bucket and then throws the difference
away; billing it to the method's slot as well costs one add.

Inclusive of whatever the handler calls into, including scopes that charge
themselves elsewhere. For ranking handlers that is the useful reading, and the
per-bucket totals stay exclusive as they were.

rpcs3/Emu/RSX/RSXFIFO.cpp

@@ -960,7 +960,10 @@ namespace rsx
 				// call: two counter reads against a handler body, not against a loop iteration.
 				// Still costs a few percent of the bucket it splits -- read the split, not the
 				// total.
-				RSX_PROF_SCOPE(method_call);
+				// Bills the same interval to this method's slot as well, so the handlers can be
+				// ranked by cost rather than by how often they are called.
+				::rsx::prof::method_scope method_prof_scope{
+					static_cast<u32>(reg & (::rsx::prof::method_slot_count - 1)) };
 
 				method(m_ctx, reg, value);
 

rpcs3/Emu/RSX/rsx_profiler.cpp

@@ -42,6 +42,7 @@ namespace rsx::prof
 	u64 g_xform_const_calls = 0;
 	u64 g_xform_const_words = 0;
 	u32 g_method_counts[method_slot_count] = {};
+	u64 g_method_ticks[method_slot_count] = {};
 	u64 g_fifo_refill_bytes = 0;
 	u64 g_fifo_refill_stalls = 0;
 	u64 g_fifo_refill_stall_us = 0;
@@ -550,6 +551,38 @@ namespace rsx::prof
 			}
 		}
 
+		{
+			// By cost, not by volume. The two disagree: the busiest method may be a register
+			// write and a rare one may be doing all the work, and only this ranking can say.
+			std::pair<u32, u64> top[8] = {};
+			for (u32 i = 0; i < method_slot_count; i++)
+			{
+				if (!g_method_ticks[i]) continue;
+				if (g_method_ticks[i] <= top[7].second) continue;
+				top[7] = { i, g_method_ticks[i] };
+				std::sort(std::begin(top), std::end(top),
+					[](const auto& a, const auto& b) { return a.second > b.second; });
+			}
+
+			if (top[0].second)
+			{
+				std::string list;
+				for (const auto& [slot, ticks] : top)
+				{
+					if (!ticks) continue;
+					std::string scratch;
+					const auto name = rsx::get_method_name(slot << 2, scratch).second;
+					fmt::append(list, "\n\t  %-46s %7.3f ms/frame  %6.0f ns each",
+						name.empty() ? fmt::format("0x%05x", slot << 2) : std::string(name),
+						static_cast<double>(ticks) * to_ms / frames,
+						g_method_counts[slot]
+							? static_cast<double>(ticks) * to_ms * 1'000'000.0 / static_cast<double>(g_method_counts[slot])
+							: 0.0);
+				}
+				fmt::append(report, "\n\tcostliest methods%s", list);
+			}
+		}
+
 		prof_log.success("%s", report);
 
 		g_fifo_commands = 0;
@@ -564,6 +597,7 @@ namespace rsx::prof
 		g_xform_const_calls = 0;
 		g_xform_const_words = 0;
 		std::fill(std::begin(g_method_counts), std::end(g_method_counts), 0u);
+		std::fill(std::begin(g_method_ticks), std::end(g_method_ticks), 0ull);
 		g_fifo_refills = 0;
 		g_fifo_refill_bytes = 0;
 		g_fifo_refill_stalls = 0;

rpcs3/Emu/RSX/rsx_profiler.h

@@ -362,6 +362,60 @@ namespace rsx::prof
 	inline constexpr usz method_slot_count = 0x4000;
 	extern u32 g_method_counts[method_slot_count];
 
+	/**
+	 * Counter ticks spent inside each method's handler, indexed the same way as the counts.
+	 *
+	 * The handler bodies are 60% of the RSX thread in Arkham City and the dispatch machinery
+	 * around them is 3.5%, so the question is which handlers, and volume does not answer it:
+	 * the busiest method by count may be trivial and a rare one may be doing the work.
+	 *
+	 * Free to collect. The dispatch site already brackets the call with two counter reads to
+	 * fill the method_call bucket; this keeps the difference instead of discarding it.
+	 */
+	extern u64 g_method_ticks[method_slot_count];
+
+	/**
+	 * Bucket switch that also bills the elapsed time to a method slot.
+	 *
+	 * Inclusive of anything the handler calls into, including scopes that charge themselves
+	 * elsewhere -- for finding which handler is expensive that is the useful reading, and the
+	 * per-bucket totals remain exclusive as before.
+	 */
+	class method_scope
+	{
+		bucket m_prev;
+		bool m_active;
+		u32 m_slot;
+		u64 m_start;
+
+	public:
+		explicit method_scope(u32 slot)
+			: m_prev(bucket::unclassified)
+			, m_active(g_enabled.load(std::memory_order_relaxed) &&
+				current_thread_token() == g_owner_thread)
+			, m_slot(slot)
+			, m_start(0)
+		{
+			if (m_active) [[unlikely]]
+			{
+				m_prev = switch_to(bucket::method_call);
+				m_start = g_last_switch;
+			}
+		}
+
+		~method_scope()
+		{
+			if (m_active) [[unlikely]]
+			{
+				switch_to(m_prev);
+				g_method_ticks[m_slot] += g_last_switch - m_start;
+			}
+		}
+
+		method_scope(const method_scope&) = delete;
+		method_scope& operator=(const method_scope&) = delete;
+	};
+
 	// Refills that could not take their data immediately and fell into the retry spin, plus
 	// the microseconds burned there. That spin is billed to the FIFO bucket rather than to
 	// idle, so without these there is no way to tell RSX doing work from RSX waiting on the