diff --git a/Common/GPU/MiscTypes.h b/Common/GPU/MiscTypes.h index e0e6d06499..9a72806c6a 100644 --- a/Common/GPU/MiscTypes.h +++ b/Common/GPU/MiscTypes.h @@ -20,13 +20,14 @@ typedef std::function InvalidationCallback; // These are separate from FrameData because we store some history of these. // Also, this might be joined with more non-GPU timing information later. struct FrameTimeData { + uint64_t frameId; double frameBegin; double afterFenceWait; double firstSubmit; double queuePresent; + double actualPresent; double desiredPresentTime; - double actualPresentTime; double earliestPresentTime; double presentMargin; }; diff --git a/Common/GPU/Vulkan/VulkanFrameData.cpp b/Common/GPU/Vulkan/VulkanFrameData.cpp index 482b6160cf..82a2d3958e 100644 --- a/Common/GPU/Vulkan/VulkanFrameData.cpp +++ b/Common/GPU/Vulkan/VulkanFrameData.cpp @@ -113,9 +113,9 @@ VkResult FrameData::QueuePresent(VulkanContext *vulkan, FrameDataShared &shared) // Can't move these into the if. VkPresentIdKHR presentID{ VK_STRUCTURE_TYPE_PRESENT_ID_KHR }; VkPresentTimesInfoGOOGLE presentGOOGLE{ VK_STRUCTURE_TYPE_PRESENT_TIMES_INFO_GOOGLE }; - VkPresentTimeGOOGLE presentTimeGOOGLE{ (uint32_t)frameID, 0 }; // it's ok to truncate this. it'll wrap around and work (if we ever reach 4 billion frames..) + VkPresentTimeGOOGLE presentTimeGOOGLE{ (uint32_t)frameId, 0 }; // it's ok to truncate this. it'll wrap around and work (if we ever reach 4 billion frames..) if (vulkan->Extensions().KHR_present_id && vulkan->GetDeviceFeatures().enabled.presentId.presentId) { - presentID.pPresentIds = &frameID; + presentID.pPresentIds = &frameId; presentID.swapchainCount = 1; present.pNext = &presentID; } else if (vulkan->Extensions().GOOGLE_display_timing) { diff --git a/Common/GPU/Vulkan/VulkanFrameData.h b/Common/GPU/Vulkan/VulkanFrameData.h index 42559e37fc..0c50e8c61a 100644 --- a/Common/GPU/Vulkan/VulkanFrameData.h +++ b/Common/GPU/Vulkan/VulkanFrameData.h @@ -72,7 +72,6 @@ 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; diff --git a/Common/GPU/Vulkan/VulkanRenderManager.cpp b/Common/GPU/Vulkan/VulkanRenderManager.cpp index 23a0eec6de..1e9b22c562 100644 --- a/Common/GPU/Vulkan/VulkanRenderManager.cpp +++ b/Common/GPU/Vulkan/VulkanRenderManager.cpp @@ -546,16 +546,42 @@ void VulkanRenderManager::PresentWaitThreadFunc() { 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++; - + if (VK_SUCCESS == 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::PollPresentTiming() { + // For VK_GOOGLE_display_timing, we need to poll. + + // Poll for information about completed frames. + // NOTE: We seem to get the information pretty late! Like after 6 frames, which is quite weird. + // Tested on POCO F4. + if (vulkan_->Extensions().GOOGLE_display_timing) { + uint32_t count = 0; + vkGetPastPresentationTimingGOOGLE(vulkan_->GetDevice(), vulkan_->GetSwapchain(), &count, nullptr); + if (count > 0) { + VkPastPresentationTimingGOOGLE *timings = new VkPastPresentationTimingGOOGLE[count]; + vkGetPastPresentationTimingGOOGLE(vulkan_->GetDevice(), vulkan_->GetSwapchain(), &count, timings); + for (uint32_t i = 0; i < count; i++) { + uint64_t presentId = timings[i].presentID; + frameTimeData_[presentId].actualPresent = from_time_raw(timings[i].actualPresentTime); + frameTimeData_[presentId].desiredPresentTime = from_time_raw(timings[i].desiredPresentTime); + frameTimeData_[presentId].earliestPresentTime = from_time_raw(timings[i].earliestPresentTime); + double presentMargin = from_time_raw_relative(timings[i].presentMargin); + frameTimeData_[presentId].presentMargin = presentMargin; + } + delete[] timings; + } + } +} + + void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfiler) { double frameBeginTime = time_now_d() VLOG("BeginFrame"); @@ -582,36 +608,19 @@ void VulkanRenderManager::BeginFrame(bool enableProfiling, bool enableLogProfile } vkResetFences(device, 1, &frameData.fence); - // Poll for information about completed frames. - if (vulkan_->Extensions().GOOGLE_display_timing) { - uint32_t count = 0; - vkGetPastPresentationTimingGOOGLE(vulkan_->GetDevice(), vulkan_->GetSwapchain(), &count, nullptr); - if (count > 0) { - VkPastPresentationTimingGOOGLE *timings = new VkPastPresentationTimingGOOGLE[count]; - vkGetPastPresentationTimingGOOGLE(vulkan_->GetDevice(), vulkan_->GetSwapchain(), &count, timings); - for (uint32_t i = 0; i < count; i++) { - uint64_t presentId = timings[i].presentID; - frameTimeData_[presentId].actualPresent = from_time_raw(timings[i].actualPresentTime); - frameTimeData_[presentId].desiredPresentTime = from_time_raw(timings[i].desiredPresentTime); - frameTimeData_[presentId].earliestPresentTime = from_time_raw(timings[i].earliestPresentTime); - frameTimeData_[presentId].presentMargin = from_time_raw(timings[i].presentMargin); - INFO_LOG(G3D, "presentID: %llu : %f", (unsigned long long)presentId, frameTimeData_[presentId].actualPresent); - } - delete[] timings; - } - } + uint64_t frameId = frameIdGen_++; + + PollPresentTiming(); int validBits = vulkan_->GetQueueFamilyProperties(vulkan_->GetGraphicsQueueFamilyIndex()).timestampValidBits; // 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; frameTimeData_[frameId] = {}; + frameTimeData_[frameId].frameId = frameId; frameTimeData_[frameId].frameBegin = frameBeginTime; frameTimeData_[frameId].afterFenceWait = time_now_d(); diff --git a/Common/GPU/Vulkan/VulkanRenderManager.h b/Common/GPU/Vulkan/VulkanRenderManager.h index 43d7c0f6b9..7625f5f446 100644 --- a/Common/GPU/Vulkan/VulkanRenderManager.h +++ b/Common/GPU/Vulkan/VulkanRenderManager.h @@ -481,6 +481,7 @@ private: void StopThread(); void PresentWaitThreadFunc(); + void PollPresentTiming(); FrameDataShared frameDataShared_; diff --git a/Common/TimeUtil.cpp b/Common/TimeUtil.cpp index af45690e98..b149d16345 100644 --- a/Common/TimeUtil.cpp +++ b/Common/TimeUtil.cpp @@ -54,6 +54,9 @@ double from_time_raw(uint64_t raw_time) { return (double)raw_time * (1.0 / nanos); } +double from_time_raw_relative(uint64_t raw_time) { + return from_time_raw(raw_time); +} #elif PPSSPP_PLATFORM(ANDROID) || PPSSPP_PLATFORM(LINUX) || PPSSPP_PLATFORM(MAC) || PPSSPP_PLATFORM(IOS) @@ -78,6 +81,10 @@ double time_now_d() { return from_time_raw(raw_time); } +double from_time_raw_relative(uint64_t raw_time) { + return (double)raw_time * (1.0 / nanos); +} + #else double time_now_d() { @@ -99,6 +106,10 @@ double from_time_raw(uint64_t raw_time) { return (double)raw_time * (1.0 / nanos); } +double from_time_raw_relative(uint64_t raw_time) { + return from_time_raw(raw_time); +} + #endif void sleep_ms(int ms) { diff --git a/Common/TimeUtil.h b/Common/TimeUtil.h index 8e224872b1..0ba1d52adf 100644 --- a/Common/TimeUtil.h +++ b/Common/TimeUtil.h @@ -11,6 +11,7 @@ uint64_t time_now_raw(); // This is only interesting for Linux, in relation to VK_GOOGLE_display_timing. double from_time_raw(uint64_t raw_time); +double from_time_raw_relative(uint64_t raw_time); // Sleep. Does not necessarily have millisecond granularity, especially on Windows. void sleep_ms(int ms); diff --git a/UI/DebugOverlay.cpp b/UI/DebugOverlay.cpp index d1f4622086..e5e34033e1 100644 --- a/UI/DebugOverlay.cpp +++ b/UI/DebugOverlay.cpp @@ -104,45 +104,47 @@ static void DrawFrameTiming(UIContext *ctx, const Bounds &bounds) { char statBuf[1024]{}; - FrameTimeData data = ctx->GetDrawContext()->GetFrameTimeData(4); - - if (data.frameBegin == 0.0) { - snprintf(statBuf, sizeof(statBuf), "(Frame timing collection not supported on this backend)"); - } else { - 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; - double margin = data.presentMargin; - double computedMargin = data.actualPresent - data.queuePresent; - - char presentStats[256] = ""; - if (data.actualPresent != 0.0) { - snprintf(presentStats, sizeof(presentStats), - "* Actual present: %0.1f ms\n" - "* Margin: %0.1f ms (%0.1f computed)\n", - actualPresentLatency_s * 1000.0, - margin * 1000.0, - computedMargin * 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" - "%s", - fenceLatency_s * 1000.0, - submitLatency_s * 1000.0, - queuePresentLatency_s * 1000.0, - presentStats - ); - } - ctx->Flush(); ctx->BindFontTexture(); ctx->Draw()->SetFontScale(0.5f, 0.5f); - ctx->Draw()->DrawTextRect(ubuntu24, statBuf, bounds.x + 11, bounds.y + 51, bounds.w - 20, bounds.h - 30, 0xc0000000, FLAG_DYNAMIC_ASCII); - ctx->Draw()->DrawTextRect(ubuntu24, statBuf, bounds.x + 10, bounds.y + 50, bounds.w - 20, bounds.h - 30, 0xFFFFFFFF, FLAG_DYNAMIC_ASCII); + + for (int i = 0; i < 8; i++) { + FrameTimeData data = ctx->GetDrawContext()->GetFrameTimeData(6 + i); + if (data.frameBegin == 0.0) { + snprintf(statBuf, sizeof(statBuf), "(Frame timing collection not supported on this backend)"); + } else { + 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; + double presentMargin = data.presentMargin; + double computedMargin = data.actualPresent - data.queuePresent; + + char presentStats[256] = ""; + if (data.actualPresent != 0.0) { + snprintf(presentStats, sizeof(presentStats), + "* Present: %0.1f ms\n" + "* Margin: %0.1f ms\n" + "* Margin(c): %0.1f ms\n", + actualPresentLatency_s * 1000.0, + presentMargin * 1000.0, + computedMargin * 1000.0); + } + snprintf(statBuf, sizeof(statBuf), + "%llu: From start of frame to event:\n" + "* Past fence: %0.1f ms\n" + "* Submit #1: %0.1f ms\n" + "* Queue-p: %0.1f ms\n" + "%s", + (long long)data.frameId, + fenceLatency_s * 1000.0, + submitLatency_s * 1000.0, + queuePresentLatency_s * 1000.0, + presentStats + ); + } + ctx->Draw()->DrawTextRect(ubuntu24, statBuf, bounds.x + 10 + i * 150, bounds.y + 50, bounds.w - 20, bounds.h - 30, 0xFFFFFFFF, FLAG_DYNAMIC_ASCII); + } ctx->Draw()->SetFontScale(1.0f, 1.0f); ctx->Flush(); ctx->RebindTexture(); diff --git a/UI/RetroAchievementScreens.cpp b/UI/RetroAchievementScreens.cpp index a09bfa87b4..29d4beff95 100644 --- a/UI/RetroAchievementScreens.cpp +++ b/UI/RetroAchievementScreens.cpp @@ -388,15 +388,15 @@ void RetroAchievementsSettingsScreen::CreateCustomizeTab(UI::ViewGroup *viewGrou viewGroup->Add(new AudioFileChooser(&g_Config.sAchievementsUnlockAudioFile, ac->T("Achievement unlocked"), UISound::ACHIEVEMENT_UNLOCKED)); viewGroup->Add(new AudioFileChooser(&g_Config.sAchievementsLeaderboardSubmitAudioFile, ac->T("Leaderboard score submission"), UISound::LEADERBOARD_SUBMITTED)); - static const char *positions[] = { "Bottom Left", "Bottom Center", "Bottom Right", "Top Left", "Top Center", "Top Right", "Center Left", "Center Right", "None" }; + static const char *positions[] = { "None", "Bottom Left", "Bottom Center", "Bottom Right", "Top Left", "Top Center", "Top Right", "Center Left", "Center Right" }; viewGroup->Add(new ItemHeader(ac->T("Notifications"))); - viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsLeaderboardStartedOrFailedPos, ac->T("Leaderboard attempt started or failed"), positions, 0, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); - viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsLeaderboardSubmittedPos, ac->T("Leaderboard result submitted"), positions, 0, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); - viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsLeaderboardTrackerPos, ac->T("Leaderboard tracker"), positions, 0, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); - viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsUnlockedPos, ac->T("Achievement unlocked"), positions, 0, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); - viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsChallengePos, ac->T("Challenge indicator"), positions, 0, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); - viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsProgressPos, ac->T("Achievement progress"), positions, 0, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); + viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsLeaderboardStartedOrFailedPos, ac->T("Leaderboard attempt started or failed"), positions, -1, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); + viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsLeaderboardSubmittedPos, ac->T("Leaderboard result submitted"), positions, -1, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); + viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsLeaderboardTrackerPos, ac->T("Leaderboard tracker"), positions, -1, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); + viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsUnlockedPos, ac->T("Achievement unlocked"), positions, -1, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); + viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsChallengePos, ac->T("Challenge indicator"), positions, -1, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); + viewGroup->Add(new PopupMultiChoice(&g_Config.iAchievementsProgressPos, ac->T("Achievement progress"), positions, -1, ARRAY_SIZE(positions), I18NCat::DIALOG, screenManager()))->SetEnabledPtr(&g_Config.bAchievementsEnable); } void RetroAchievementsSettingsScreen::CreateDeveloperToolsTab(UI::ViewGroup *viewGroup) {