From 12efc846325422137e3dce89b396842912a0f6b6 Mon Sep 17 00:00:00 2001 From: Scott Romero <24445312+AMZN-ScottR@users.noreply.github.com> Date: Tue, 30 Nov 2021 08:27:27 -0800 Subject: [PATCH] [development] minor Profiler gem fixes (#5473) Fixed incorrect frame boundary guess when loading a profile capture Added some missing default initializers Removed implicit dependency on Atom timing marker constants Fixed issue with small visualizer viewport bounds when loading a saved capture Signed-off-by: AMZN-ScottR 24445312+AMZN-ScottR@users.noreply.github.com --- .../Statistics/StatisticalProfilerProxy.h | 16 ++++++++ .../AzCore/Statistics/StatisticsManager.h | 14 ++++++- Gems/Profiler/Code/Source/CpuProfilerImpl.h | 2 +- .../Profiler/Code/Source/ImGuiCpuProfiler.cpp | 41 +++++++++++-------- Gems/Profiler/Code/Source/ImGuiCpuProfiler.h | 7 ++-- 5 files changed, 57 insertions(+), 23 deletions(-) diff --git a/Code/Framework/AzCore/AzCore/Statistics/StatisticalProfilerProxy.h b/Code/Framework/AzCore/AzCore/Statistics/StatisticalProfilerProxy.h index 278b2ecc98..7fae0ca354 100644 --- a/Code/Framework/AzCore/AzCore/Statistics/StatisticalProfilerProxy.h +++ b/Code/Framework/AzCore/AzCore/Statistics/StatisticalProfilerProxy.h @@ -157,6 +157,22 @@ namespace AZ::Statistics } } + void GetAllStatistics(AZStd::vector& stats) + { + for (auto& iter : m_profilers) + { + iter.second.m_profiler.GetStatsManager().GetAllStatistics(stats); + } + } + + void GetAllStatisticsOfUnits(AZStd::vector& stats, const char* units) + { + for (auto& iter : m_profilers) + { + iter.second.m_profiler.GetStatsManager().GetAllStatisticsOfUnits(stats, units); + } + } + private: struct ProfilerInfo { diff --git a/Code/Framework/AzCore/AzCore/Statistics/StatisticsManager.h b/Code/Framework/AzCore/AzCore/Statistics/StatisticsManager.h index 5984701f4e..dc97de40c1 100644 --- a/Code/Framework/AzCore/AzCore/Statistics/StatisticsManager.h +++ b/Code/Framework/AzCore/AzCore/Statistics/StatisticsManager.h @@ -56,13 +56,25 @@ namespace AZ void GetAllStatistics(AZStd::vector& vector) { - for (auto const& it : m_statistics) + for (const auto& it : m_statistics) { NamedRunningStatistic* stat = it.second; vector.push_back(stat); } } + void GetAllStatisticsOfUnits(AZStd::vector& vector, const char* units) + { + for (const auto& it : m_statistics) + { + NamedRunningStatistic* stat = it.second; + if (stat->GetUnits() == units) + { + vector.push_back(stat); + } + } + } + //! Helper method to apply units to statistics with empty units string. AZ::u32 ApplyUnits(const AZStd::string& units) { diff --git a/Gems/Profiler/Code/Source/CpuProfilerImpl.h b/Gems/Profiler/Code/Source/CpuProfilerImpl.h index 6611fbd1e5..c97e45e69c 100644 --- a/Gems/Profiler/Code/Source/CpuProfilerImpl.h +++ b/Gems/Profiler/Code/Source/CpuProfilerImpl.h @@ -150,7 +150,7 @@ namespace Profiler AZStd::mutex m_continuousCaptureEndingMutex; - AZStd::atomic_bool m_continuousCaptureInProgress; + AZStd::atomic_bool m_continuousCaptureInProgress = false; // Stores multiple frames of profiling data, size is controlled by MaxFramesToSave. Flushed when EndContinuousCapture is called. // Ring buffer so that we can have fast append of new data + removal of old profiling data with good cache locality. diff --git a/Gems/Profiler/Code/Source/ImGuiCpuProfiler.cpp b/Gems/Profiler/Code/Source/ImGuiCpuProfiler.cpp index 26c2f9f974..1cb13fe4ac 100644 --- a/Gems/Profiler/Code/Source/ImGuiCpuProfiler.cpp +++ b/Gems/Profiler/Code/Source/ImGuiCpuProfiler.cpp @@ -23,9 +23,13 @@ #include #include #include +#include namespace Profiler { + constexpr AZStd::sys_time_t ProfilerViewEdgePadding = 5000; + constexpr size_t InitialCpuTimingStatsAllocation = 8; + namespace CpuProfilerImGuiHelper { float TicksToMs(double ticks) @@ -435,6 +439,11 @@ namespace Profiler m_tableData.clear(); m_groupRegionMap.clear(); + // Since we don't serialize the frame boundaries, we will use "Component application simulation tick" from + // ComponentApplication::Tick as a heuristic. + static const AZ::Name::Hash frameBoundaryHash = AZ::Name("Component application simulation tick").GetHash(); + + AZStd::sys_time_t frameTime = 0; for (const auto& entry : deserializedData) { const auto [groupNameItr, wasGroupNameInserted] = m_deserializedStringPool.emplace(entry.m_groupName.GetCStr()); @@ -445,10 +454,12 @@ namespace Profiler const CachedTimeRegion newRegion(*groupRegionNameItr, entry.m_stackDepth, entry.m_startTick, entry.m_endTick); m_savedData[entry.m_threadId].push_back(newRegion); - // Since we don't serialize the frame boundaries, we need to use the RPI's OnSystemTick event as a heuristic. - const static AZ::Name frameBoundaryName = AZ::Name("RPISystem: OnSystemTick"); - if (entry.m_regionName == frameBoundaryName) + if (entry.m_regionName.GetHash() == frameBoundaryHash) { + if (!m_frameEndTicks.empty()) + { + frameTime = entry.m_endTick - m_frameEndTicks.back(); + } m_frameEndTicks.push_back(entry.m_endTick); } @@ -462,9 +473,9 @@ namespace Profiler m_groupRegionMap[*groupNameItr][*regionNameItr].RecordRegion(newRegion, entry.m_threadId); } - // Update viewport bounds with some added UX fudge factor - m_viewportStartTick = deserializedData.back().m_startTick - 1000; - m_viewportEndTick = deserializedData.back().m_endTick + 1000; + // Update viewport bounds to the estimated final frame time with some padding + m_viewportStartTick = m_frameEndTicks.back() - frameTime - ProfilerViewEdgePadding; + m_viewportEndTick = m_frameEndTicks.back() + ProfilerViewEdgePadding; // Invariant: each vector in m_savedData must be sorted so that we can efficiently cull region data. for (auto& [threadId, singleThreadData] : m_savedData) @@ -642,21 +653,13 @@ namespace Profiler m_cpuTimingStatisticsWhenPause.clear(); if (auto statsProfiler = AZ::Interface::Get(); statsProfiler) { - auto& rhiMetrics = statsProfiler->GetProfiler(AZ_CRC_CE("RHI")); - - const NamedRunningStatistic* frameTimeMetric = rhiMetrics.GetStatistic(AZ_CRC_CE("Frame to Frame Time")); - if (frameTimeMetric) - { - m_frameToFrameTime = static_cast(frameTimeMetric->GetMostRecentSample()); - } - AZStd::vector statistics; - rhiMetrics.GetStatsManager().GetAllStatistics(statistics); + statistics.reserve(InitialCpuTimingStatsAllocation); + statsProfiler->GetAllStatisticsOfUnits(statistics, "clocks"); for (NamedRunningStatistic* stat : statistics) { m_cpuTimingStatisticsWhenPause.push_back({ stat->GetName(), stat->GetMostRecentSample() }); - stat->Reset(); } } } @@ -731,7 +734,11 @@ namespace Profiler void ImGuiCpuProfiler::CullFrameData() { - const AZStd::sys_time_t deleteBeforeTick = AZStd::GetTimeNowTicks() - m_frameToFrameTime * m_framesToCollect; + const AZ::TimeUs delta = AZ::GetRealTickDeltaTimeUs(); + const float deltaTimeInSeconds = AZ::TimeUsToSeconds(delta); + const AZStd::sys_time_t frameToFrameTime = static_cast(deltaTimeInSeconds * AZStd::GetTimeTicksPerSecond()); + + const AZStd::sys_time_t deleteBeforeTick = AZStd::GetTimeNowTicks() - frameToFrameTime * m_framesToCollect; // Remove old frame boundary data auto firstBoundaryToKeepItr = AZStd::upper_bound(m_frameEndTicks.begin(), m_frameEndTicks.end(), deleteBeforeTick); diff --git a/Gems/Profiler/Code/Source/ImGuiCpuProfiler.h b/Gems/Profiler/Code/Source/ImGuiCpuProfiler.h index 2e01b8fd6b..d5d27632f8 100644 --- a/Gems/Profiler/Code/Source/ImGuiCpuProfiler.h +++ b/Gems/Profiler/Code/Source/ImGuiCpuProfiler.h @@ -89,7 +89,7 @@ namespace Profiler struct CpuTimingEntry { const AZStd::string& m_name; - double m_executeDuration; + double m_executeDuration = 0; }; ImGuiCpuProfiler() = default; @@ -175,8 +175,8 @@ namespace Profiler AZ::u64 m_savedRegionCount = 0; // Viewport tick bounds, these are used to convert tick space -> screen space and cull so we only draw onscreen objects - AZStd::sys_time_t m_viewportStartTick; - AZStd::sys_time_t m_viewportEndTick; + AZStd::sys_time_t m_viewportStartTick = 0; + AZStd::sys_time_t m_viewportEndTick = 0; // Map to store each thread's TimeRegions, individual vectors are sorted by start tick // note: we use size_t as a proxy for thread_id because native_thread_id_type differs differs from @@ -215,7 +215,6 @@ namespace Profiler // Last captured CPU timing statistics AZStd::vector m_cpuTimingStatisticsWhenPause; - AZStd::sys_time_t m_frameToFrameTime{}; AZ::IO::FixedMaxPath m_lastCapturedFilePath;