Use VK_KHR_present_wait to get numbers on how much latency we have to screen

This extension is not available on Android, there they have
VK_GOOGLE_display_timing, which they also have an abstraction library
for, so will look at that later.

Early part of work on #17685

Common/GPU/MiscTypes.h

@@ -24,4 +24,5 @@ struct FrameTimeData {
 	double afterFenceWait;
 	double firstSubmit;
 	double queuePresent;
+	double actualPresent;
 };

Common/GPU/Vulkan/VulkanContext.cpp

@@ -598,6 +598,7 @@ void VulkanContext::ChooseDevice(int physical_device) {
 		features2.pNext = &multiViewFeatures;
 		multiViewFeatures.pNext = &presentWaitFeatures;
 		presentWaitFeatures.pNext = &presentIdFeatures;
+		presentIdFeatures.pNext = nullptr;
 
 		vkGetPhysicalDeviceFeatures2KHR(physical_devices_[physical_device_], &features2);
 		deviceFeatures_.available.standard = features2.features;
@@ -709,6 +710,9 @@ VkResult VulkanContext::CreateDevice() {
 		device_info.pNext = &features2;
 		features2.features = deviceFeatures_.enabled.standard;
 		features2.pNext = &deviceFeatures_.enabled.multiview;
+		deviceFeatures_.enabled.multiview.pNext = &deviceFeatures_.enabled.presentWait;
+		deviceFeatures_.enabled.presentWait.pNext = &deviceFeatures_.enabled.presentId;
+		deviceFeatures_.enabled.presentId.pNext = nullptr;
 	} else {
 		device_info.pEnabledFeatures = &deviceFeatures_.enabled.standard;
 	}

Common/GPU/Vulkan/VulkanDebug.cpp

@@ -82,6 +82,10 @@ VKAPI_ATTR VkBool32 VKAPI_CALL VulkanDebugUtilsCallback(
 		// Extended validation (ARM best practices)
 		// Non-fifo validation not recommended
 		return false;
+	case 337425955:
+		// False positive
+		// https://github.com/KhronosGroup/Vulkan-ValidationLayers/issues/3615
+		return false;
 	default:
 		break;
 	}

Common/GPU/Vulkan/VulkanFrameData.cpp

@@ -110,6 +110,13 @@ VkResult FrameData::QueuePresent(VulkanContext *vulkan, FrameDataShared &shared)
 	present.pWaitSemaphores = &shared.renderingCompleteSemaphore;
 	present.waitSemaphoreCount = 1;
 
+	VkPresentIdKHR presentID{ VK_STRUCTURE_TYPE_PRESENT_ID_KHR };
+	if (vulkan->Extensions().KHR_present_id && vulkan->GetDeviceFeatures().enabled.presentId.presentId) {
+		presentID.pPresentIds = &frameID;
+		presentID.swapchainCount = 1;
+		present.pNext = &presentID;
+	}
+
 	return vkQueuePresentKHR(vulkan->GetGraphicsQueue(), &present);
 }
 

Common/GPU/Vulkan/VulkanFrameData.h

@@ -72,6 +72,7 @@ struct FrameData {
 	std::mutex fenceMutex;
 	std::condition_variable fenceCondVar;
 	bool readyForFence = true;
+	uint64_t frameID;  // always incrementing, set at the start of each frame.
 
 	VkFence fence = VK_NULL_HANDLE;
 

Common/GPU/Vulkan/VulkanLoader.cpp

@@ -223,11 +223,14 @@ PFN_vkCmdInsertDebugUtilsLabelEXT	 vkCmdInsertDebugUtilsLabelEXT;
 PFN_vkSetDebugUtilsObjectNameEXT     vkSetDebugUtilsObjectNameEXT;
 PFN_vkSetDebugUtilsObjectTagEXT      vkSetDebugUtilsObjectTagEXT;
 
+// Assorted other extensions.
 PFN_vkGetBufferMemoryRequirements2KHR vkGetBufferMemoryRequirements2KHR;
 PFN_vkGetImageMemoryRequirements2KHR vkGetImageMemoryRequirements2KHR;
 PFN_vkGetPhysicalDeviceProperties2KHR vkGetPhysicalDeviceProperties2KHR;
 PFN_vkGetPhysicalDeviceFeatures2KHR vkGetPhysicalDeviceFeatures2KHR;
 PFN_vkCreateRenderPass2KHR vkCreateRenderPass2KHR;
+PFN_vkWaitForPresentKHR vkWaitForPresentKHR;
+
 } // namespace PPSSPP_VK
 
 using namespace PPSSPP_VK;
@@ -725,6 +728,7 @@ void VulkanLoadDeviceFunctions(VkDevice device, const VulkanExtensions &enabledE
 	LOAD_DEVICE_FUNC(device, vkCmdNextSubpass);
 	LOAD_DEVICE_FUNC(device, vkCmdEndRenderPass);
 	LOAD_DEVICE_FUNC(device, vkCmdExecuteCommands);
+	LOAD_DEVICE_FUNC(device, vkWaitForPresentKHR);
 
 	if (enabledExtensions.KHR_dedicated_allocation) {
 		LOAD_DEVICE_FUNC(device, vkGetBufferMemoryRequirements2KHR);

Common/GPU/Vulkan/VulkanLoader.h

@@ -235,6 +235,7 @@ extern PFN_vkGetMemoryHostPointerPropertiesEXT vkGetMemoryHostPointerPropertiesE
 extern PFN_vkGetPhysicalDeviceProperties2KHR vkGetPhysicalDeviceProperties2KHR;
 extern PFN_vkGetPhysicalDeviceFeatures2KHR vkGetPhysicalDeviceFeatures2KHR;
 extern PFN_vkCreateRenderPass2KHR vkCreateRenderPass2KHR;
+extern PFN_vkWaitForPresentKHR vkWaitForPresentKHR;
 } // namespace PPSSPP_VK
 
 // For fast extension-enabled checks.

Common/GPU/Vulkan/VulkanRenderManager.cpp

@@ -303,6 +303,11 @@ bool VulkanRenderManager::CreateBackbuffers() {
 		}
 		INFO_LOG(G3D, "Starting Vulkan compiler thread");
 		compileThread_ = std::thread(&VulkanRenderManager::CompileThreadFunc, this);
+
+		if (vulkan_->GetDeviceFeatures().enabled.presentWait.presentWait) {
+			INFO_LOG(G3D, "Starting Vulkan present wait thread");
+			presentWaitThread_ = std::thread(&VulkanRenderManager::PresentWaitThreadFunc, this);
+		}
 	}
 	return true;
 }
@@ -319,9 +324,13 @@ void VulkanRenderManager::StopThread() {
 		pushCondVar_.notify_one();
 	}
 
-	// Compiler thread still relies on this.
+	// Compiler and present thread still relies on this.
 	run_ = false;
 
+	if (presentWaitThread_.joinable()) {
+		presentWaitThread_.join();
+	}
+
 	// Stop the thread.
 	if (useRenderThread_) {
 		thread_.join();
@@ -531,6 +540,22 @@ void VulkanRenderManager::ThreadFunc() {
 	VLOG("PULL: Quitting");
 }
 
+void VulkanRenderManager::PresentWaitThreadFunc() {
+	SetCurrentThreadName("PresentWait");
+
+	uint64_t waitedId = frameIdGen_;
+	while (run_) {
+		const uint64_t timeout = 1000000000ULL;  // 1 sec
+		vkWaitForPresentKHR(vulkan_->GetDevice(), vulkan_->GetSwapchain(), waitedId, timeout);
+		frameTimeData_[waitedId].actualPresent = time_now_d();
+		waitedId++;
+
+		_dbg_assert_(waitedId <= frameIdGen_);
+	}
+
+	INFO_LOG(G3D, "Leaving PresentWaitThreadFunc()");
+}
+
 void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfiler) {
 	double frameBeginTime = time_now_d()
 	VLOG("BeginFrame");
@@ -538,7 +563,6 @@ void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfile
 
 	int curFrame = vulkan_->GetCurFrame();
 	FrameData &frameData = frameData_[curFrame];
-
 	VLOG("PUSH: Fencing %d", curFrame);
 
 	// Makes sure the submission from the previous time around has happened. Otherwise
@@ -563,6 +587,7 @@ void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfile
 	// Can't set this until after the fence.
 	frameData.profile.enabled = enableProfiling;
 	frameData.profile.timestampsEnabled = enableProfiling && validBits > 0;
+	frameData.frameID = frameIdGen_++;
 
 	uint64_t frameId = ++frameIdGen_;
 	frameData.frameId = frameId;

Common/GPU/Vulkan/VulkanRenderManager.h

@@ -480,6 +480,8 @@ private:
 	void FlushSync();
 	void StopThread();
 
+	void PresentWaitThreadFunc();
+
 	FrameDataShared frameDataShared_;
 
 	FrameData frameData_[VulkanContext::MAX_INFLIGHT_FRAMES];
@@ -535,6 +537,9 @@ private:
 	std::mutex compileMutex_;
 	std::vector<CompileQueueEntry> compileQueue_;
 
+	// Thread for measuring presentation delay.
+	std::thread presentWaitThread_;
+
 	// pipelines to check and possibly create at the end of the current render pass.
 	std::vector<VKRGraphicsPipeline *> pipelinesToCheck_;
 

UI/DebugOverlay.cpp

@@ -112,15 +112,24 @@ static void DrawFrameTiming(UIContext *ctx, const Bounds &bounds) {
 		double fenceLatency_s = data.afterFenceWait - data.frameBegin;
 		double submitLatency_s = data.firstSubmit - data.frameBegin;
 		double queuePresentLatency_s = data.queuePresent - data.frameBegin;
+		double actualPresentLatency_s = data.actualPresent - data.frameBegin;
 
+		char presentStats[256] = "";
+		if (data.actualPresent != 0.0) {
+			snprintf(presentStats, sizeof(presentStats),
+				"* Actual present: %0.1f ms\n",
+				actualPresentLatency_s * 1000.0);
+		}
 		snprintf(statBuf, sizeof(statBuf),
 			"Time from start of frame to event:\n"
 			"* Past the fence: %0.1f ms\n"
 			"* First submit: %0.1f ms\n"
-			"* Queue-present: %0.1f ms\n",
+			"* Queue-present: %0.1f ms\n"
+			"%s",
 			fenceLatency_s * 1000.0,
 			submitLatency_s * 1000.0,
-			queuePresentLatency_s * 1000.0
+			queuePresentLatency_s * 1000.0,
+			presentStats
 		);
 	}