softgpu: Expose flush reasons/times in debug stats.

GPU/Software/BinManager.cpp

@@ -20,6 +20,8 @@
 #include <mutex>
 #include "Common/Profiler/Profiler.h"
 #include "Common/Thread/ThreadManager.h"
+#include "Common/TimeUtil.h"
+#include "Core/System.h"
 #include "GPU/Software/BinManager.h"
 #include "GPU/Software/Rasterizer.h"
 #include "GPU/Software/RasterizerRectangle.h"
@@ -136,7 +138,7 @@ BinManager::~BinManager() {
 void BinManager::UpdateState() {
 	PROFILE_THIS_SCOPE("bin_state");
 	if (states_.Full())
-		Flush();
+		Flush("states");
 	stateIndex_ = (int)states_.Push(RasterizerState());
 	ComputeRasterizerState(&states_[stateIndex_]);
 	states_[stateIndex_].samplerID.cached.clut = cluts_[clutIndex_].readable;
@@ -165,12 +167,12 @@ void BinManager::UpdateState() {
 	// We don't want to overlap wrong, so flush any pending.
 	if (maxTasks_ != newMaxTasks) {
 		maxTasks_ = newMaxTasks;
-		Flush();
+		Flush("selfrender");
 	}
 
 	// Our bin sizes are based on offset, so if that changes we have to flush.
 	if (queueOffsetX_ != gstate.getOffsetX16() || queueOffsetY_ != gstate.getOffsetY16()) {
-		Flush();
+		Flush("offset");
 		queueOffsetX_ = gstate.getOffsetX16();
 		queueOffsetY_ = gstate.getOffsetY16();
 	}
@@ -179,7 +181,7 @@ void BinManager::UpdateState() {
 void BinManager::UpdateClut(const void *src) {
 	PROFILE_THIS_SCOPE("bin_clut");
 	if (cluts_.Full())
-		Flush();
+		Flush("cluts");
 	clutIndex_ = (int)cluts_.Push(BinClut());
 	memcpy(cluts_[clutIndex_].readable, src, sizeof(BinClut));
 }
@@ -323,7 +325,10 @@ void BinManager::Drain() {
 	}
 }
 
-void BinManager::Flush() {
+void BinManager::Flush(const char *reason) {
+	double st;
+	if (coreCollectDebugStats)
+		st = time_now_d();
 	Drain();
 	waitable_->Wait();
 	taskRanges_.clear();
@@ -341,6 +346,42 @@ void BinManager::Flush() {
 	queueRange_.y2 = 0;
 	queueOffsetX_ = -1;
 	queueOffsetY_ = -1;
+
+	if (coreCollectDebugStats) {
+		double et = time_now_d();
+		flushReasonTimes_[reason] += et - st;
+		if (et - st > slowestFlushTime_) {
+			slowestFlushTime_ = et - st;
+			slowestFlushReason_ = reason;
+		}
+	}
+}
+
+void BinManager::GetStats(char *buffer, size_t bufsize) {
+	double allTotal = 0.0;
+	double slowestTotalTime = 0.0;
+	const char *slowestTotalReason = nullptr;
+	for (auto &it : flushReasonTimes_) {
+		if (it.second > slowestTotalTime) {
+			slowestTotalTime = it.second;
+			slowestTotalReason = it.first;
+		}
+		allTotal += it.second;
+	}
+
+	snprintf(buffer, bufsize,
+		"Slowest individual flush: %s (%0.4f)\n"
+		"Slowest total flush: %s (%0.4f)\n"
+		"Total flush time: %0.4f\n",
+		slowestFlushReason_, slowestFlushTime_,
+		slowestTotalReason, slowestTotalTime,
+		allTotal);
+}
+
+void BinManager::ResetStats() {
+	flushReasonTimes_.clear();
+	slowestFlushReason_ = nullptr;
+	slowestFlushTime_ = 0.0;
 }
 
 inline BinCoords BinCoords::Intersect(const BinCoords &range) const {

GPU/Software/BinManager.h

@@ -18,6 +18,7 @@
 #pragma once
 
 #include <atomic>
+#include <unordered_map>
 #include "Common/Log.h"
 #include "GPU/Software/Rasterizer.h"
 
@@ -166,7 +167,10 @@ public:
 	void AddPoint(const VertexData &v0);
 
 	void Drain();
-	void Flush();
+	void Flush(const char *reason);
+
+	void GetStats(char *buffer, size_t bufsize);
+	void ResetStats();
 
 private:
 	static constexpr int MAX_POSSIBLE_TASKS = 64;
@@ -188,6 +192,10 @@ private:
 	std::atomic<bool> taskStatus_[MAX_POSSIBLE_TASKS];
 	BinWaitable *waitable_ = nullptr;
 
+	std::unordered_map<const char *, double> flushReasonTimes_;
+	const char *slowestFlushReason_ = nullptr;
+	double slowestFlushTime_ = 0.0;
+
 	BinCoords Scissor(BinCoords range);
 	BinCoords Range(const VertexData &v0, const VertexData &v1, const VertexData &v2);
 	BinCoords Range(const VertexData &v0, const VertexData &v1);

GPU/Software/SoftGpu.cpp

@@ -900,7 +900,7 @@ void SoftGPU::FinishDeferred() {
 }
 
 void SoftGPU::GetStats(char *buffer, size_t bufsize) {
-	snprintf(buffer, bufsize, "SoftGPU: (N/A)");
+	drawEngine_->transformUnit.GetStats(buffer, bufsize);
 }
 
 void SoftGPU::InvalidateCache(u32 addr, int size, GPUInvalidationType type)

GPU/Software/TransformUnit.cpp

@@ -609,10 +609,16 @@ void TransformUnit::SubmitPrimitive(void* vertices, void* indices, GEPrimitiveTy
 }
 
 void TransformUnit::Flush(const char *reason) {
-	binner_->Flush();
+	binner_->Flush(reason);
 	GPUDebug::NotifyDraw();
 }
 
+void TransformUnit::GetStats(char *buffer, size_t bufsize) {
+	// TODO: More stats?
+	binner_->GetStats(buffer, bufsize);
+	binner_->ResetStats();
+}
+
 void TransformUnit::FlushIfOverlap(const char *reason, uint32_t addr, uint32_t sz) {
 	if (!Memory::IsVRAMAddress(addr))
 		return;

GPU/Software/TransformUnit.h

@@ -123,6 +123,8 @@ public:
 	void FlushIfOverlap(const char *reason, uint32_t addr, uint32_t sz);
 	void NotifyClutUpdate(const void *src);
 
+	void GetStats(char *buffer, size_t bufsize);
+
 private:
 	VertexData ReadVertex(VertexReader &vreader, bool &outside_range_flag);