Vulkan profiler: Show CPU command buffer recording timing even if GPU…

… timing is unavailable
hrydgard · Jun 14, 2023 · ae29fd2 · ae29fd2
1 parent fbd10e4
commit ae29fd2
Show file tree

Hide file tree

Showing 6 changed files with 20 additions and 13 deletions.
diff --git a/Common/GPU/Vulkan/VulkanFrameData.cpp b/Common/GPU/Vulkan/VulkanFrameData.cpp
@@ -121,7 +121,7 @@ VkCommandBuffer FrameData::GetInitCmd(VulkanContext *vulkan) {
 		}
 
 		// Good spot to reset the query pool.
-		if (profilingEnabled_) {
+		if (profile.enabled) {
 			vkCmdResetQueryPool(initCmd, profile.queryPool, 0, MAX_TIMESTAMP_QUERIES);
 			vkCmdWriteTimestamp(initCmd, VK_PIPELINE_STAGE_TOP_OF_PIPE_BIT, profile.queryPool, 0);
 		}
@@ -138,7 +138,7 @@ void FrameData::SubmitPending(VulkanContext *vulkan, FrameSubmitType type, Frame
 	VkFence fenceToTrigger = VK_NULL_HANDLE;
 
 	if (hasInitCommands) {
-		if (profilingEnabled_) {
+		if (profile.enabled) {
 			// Pre-allocated query ID 1 - end of init cmdbuf.
 			vkCmdWriteTimestamp(initCmd, VK_PIPELINE_STAGE_BOTTOM_OF_PIPE_BIT, profile.queryPool, 1);
 		}

diff --git a/Common/GPU/Vulkan/VulkanFrameData.h b/Common/GPU/Vulkan/VulkanFrameData.h
@@ -19,11 +19,14 @@ enum class VKRRunType {
 };
 
 struct QueueProfileContext {
+	bool enabled = false;
+	bool timestampsEnabled = false;
 	VkQueryPool queryPool;
 	std::vector<std::string> timestampDescriptions;
 	std::string profileSummary;
 	double cpuStartTime;
 	double cpuEndTime;
+	double descWriteTime;
 };
 
 class VKRFramebuffer;
@@ -92,8 +95,7 @@ struct FrameData {
 	uint32_t curSwapchainImage = -1;
 
 	// Profiling.
-	QueueProfileContext profile;
-	bool profilingEnabled_ = false;
+	QueueProfileContext profile{};
 
 	// Async readback cache.
 	DenseHashMap<ReadbackKey, CachedReadback*, nullptr> readbacks_;

diff --git a/Common/GPU/Vulkan/VulkanQueueRunner.cpp b/Common/GPU/Vulkan/VulkanQueueRunner.cpp
@@ -339,7 +339,7 @@ void VulkanQueueRunner::PreprocessSteps(std::vector<VKRStep *> &steps) {
 }
 
 void VulkanQueueRunner::RunSteps(std::vector<VKRStep *> &steps, FrameData &frameData, FrameDataShared &frameDataShared, bool keepSteps) {
-	QueueProfileContext *profile = frameData.profilingEnabled_ ? &frameData.profile : nullptr;
+	QueueProfileContext *profile = frameData.profile.enabled ? &frameData.profile : nullptr;
 
 	if (profile)
 		profile->cpuStartTime = time_now_d();
@@ -412,7 +412,7 @@ void VulkanQueueRunner::RunSteps(std::vector<VKRStep *> &steps, FrameData &frame
 			break;
 		}
 
-		if (profile && profile->timestampDescriptions.size() + 1 < MAX_TIMESTAMP_QUERIES) {
+		if (profile && profile->timestampsEnabled && profile->timestampDescriptions.size() + 1 < MAX_TIMESTAMP_QUERIES) {
 			vkCmdWriteTimestamp(cmd, VK_PIPELINE_STAGE_BOTTOM_OF_PIPE_BIT, profile->queryPool, (uint32_t)profile->timestampDescriptions.size());
 			profile->timestampDescriptions.push_back(StepToString(step));
 		}

diff --git a/Common/GPU/Vulkan/VulkanRenderManager.cpp b/Common/GPU/Vulkan/VulkanRenderManager.cpp
@@ -552,13 +552,14 @@ void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfile
 	int validBits = vulkan_->GetQueueFamilyProperties(vulkan_->GetGraphicsQueueFamilyIndex()).timestampValidBits;
 
 	// Can't set this until after the fence.
-	frameData.profilingEnabled_ = enableProfiling && validBits > 0;
+	frameData.profile.enabled = enableProfiling;
+	frameData.profile.timestampsEnabled = enableProfiling && validBits > 0;
 
 	uint64_t queryResults[MAX_TIMESTAMP_QUERIES];
 
-	if (frameData.profilingEnabled_) {
+	if (enableProfiling) {
 		// Pull the profiling results from last time and produce a summary!
-		if (!frameData.profile.timestampDescriptions.empty()) {
+		if (!frameData.profile.timestampDescriptions.empty() && frameData.profile.timestampsEnabled) {
 			int numQueries = (int)frameData.profile.timestampDescriptions.size();
 			VkResult res = vkGetQueryPoolResults(
 				vulkan_->GetDevice(),
@@ -596,7 +597,12 @@ void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfile
 				frameData.profile.profileSummary = "(error getting GPU profile - not ready?)";
 			}
 		} else {
-			frameData.profile.profileSummary = "(no GPU profile data collected)";
+			std::stringstream str;
+			char line[256];
+			renderCPUTimeMs_.Update((frameData.profile.cpuEndTime - frameData.profile.cpuStartTime) * 1000.0);
+			renderCPUTimeMs_.Format(line, sizeof(line));
+			str << line;
+			frameData.profile.profileSummary = str.str();
 		}
 	}
 
@@ -607,7 +613,7 @@ void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfile
 	vulkan_->BeginFrame(enableLogProfiler ? GetInitCmd() : VK_NULL_HANDLE);
 
 	frameData.profile.timestampDescriptions.clear();
-	if (frameData.profilingEnabled_) {
+	if (frameData.profile.timestampsEnabled) {
 		// For various reasons, we need to always use an init cmd buffer in this case to perform the vkCmdResetQueryPool,
 		// unless we want to limit ourselves to only measure the main cmd buffer.
 		// Later versions of Vulkan have support for clearing queries on the CPU timeline, but we don't want to rely on that.

diff --git a/Common/GPU/Vulkan/VulkanRenderManager.h b/Common/GPU/Vulkan/VulkanRenderManager.h
@@ -453,8 +453,6 @@ class VulkanRenderManager {
 		return outOfDateFrames_ > VulkanContext::MAX_INFLIGHT_FRAMES;
 	}
 
-	void Invalidate(InvalidationFlags flags);
-
 	void ResetStats();
 	void DrainCompileQueue();
 

diff --git a/Common/Math/Statistics.h b/Common/Math/Statistics.h
@@ -32,6 +32,7 @@ struct SimpleStat {
 	void Format(char *buffer, size_t sz);
 
 private:
+	SimpleStat() {}
 	const char *name_;
 
 	// These are initialized in Reset().