From 487fc631eca1dd23c83e77ad06eb898ecf567570 Mon Sep 17 00:00:00 2001 From: Jacob Hilliard Date: Mon, 12 Jul 2021 16:47:33 -0700 Subject: [PATCH] Visualizer: Tabular view of function statistics Current metrics are MTPC, max time, and invocations per frame. The invocations per frame is buggy if switching between samples but I don't know how to fix that in a context-agnostic way (editor vs ASV) - resetting works for now. Signed-off-by: Jacob Hilliard --- .../Include/Atom/Utils/ImGuiCpuProfiler.h | 41 +-- .../Include/Atom/Utils/ImGuiCpuProfiler.inl | 276 +++++++++--------- 2 files changed, 153 insertions(+), 164 deletions(-) diff --git a/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.h b/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.h index 4d22458b56..695ad7e332 100644 --- a/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.h +++ b/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.h @@ -31,28 +31,29 @@ namespace AZ AZStd::sys_time_t m_endTick = 0; }; - // Stores data about a region that is agreggated from all collected frames - // Data collection can be toggled on and off through m_record. - struct RegionStatistics + struct TableRow { - float CalcAverageTimeMs() const; void RecordRegion(const AZ::RHI::CachedTimeRegion& region); + double GetAverageInvocationsPerFrame() const; - bool m_draw = false; - bool m_record = true; - u64 m_invocations = 0; - AZStd::sys_time_t m_totalTicks = 0; + static u64 ms_frames; + + AZStd::string m_groupName; + AZStd::string m_regionName; + AZStd::sys_time_t m_maxTicks; + AZStd::sys_time_t m_runningAverageTicks; + u64 m_invocations; }; //! Visual profiler for Cpu statistics. //! It uses ImGui as the library for displaying the Attachments and Heaps. - //! It shows all heaps that are being used by the RHI and how the + //! It shows all heaps that are being used by the RHI and how the FIXME //! resources are allocated in each heap. class ImGuiCpuProfiler : SystemTickBus::Handler { // Region Name -> Array of ThreadRegion entries - using RegionEntryMap = AZStd::map>; + using RegionEntryMap = AZStd::map; // Group Name -> RegionEntryMap using GroupRegionMap = AZStd::map; @@ -81,12 +82,21 @@ namespace AZ // Draw the shared header between the two windows void DrawCommonHeader(); + // Draw the region statstics table in the order specified by the pointers in m_tableData + void DrawTable(); + + // Sort the table by a given column, rearranges the pointers in m_tableData + void SortTable(ImGuiTableSortSpecs* sortSpecs); + // ImGui filter used to filter TimedRegions. ImGuiTextFilter m_timedRegionFilter; - // Saves statistical view data organized by group name -> region name -> regions + // Saves statistical view data organized by group name -> region name -> row data GroupRegionMap m_groupRegionMap; + // Saves pointers to objects in m_groupRegionMap, order reflects table ordering + AZStd::vector m_tableData; + // Pause cpu profiling. The profiler will show the statistics of the last frame before pause bool m_paused = false; @@ -120,9 +130,6 @@ namespace AZ // Draw the "Thread XXXXX" label onto the viewport void DrawThreadLabel(u64 baseRow, AZStd::thread_id threadId); - // Draws all active function statistics windows - void DrawRegionStatistics(); - // Draw the vertical lines separating frames in the timeline void DrawFrameBoundaries(); @@ -164,12 +171,8 @@ namespace AZ // Tracks the frame boundaries AZStd::vector m_frameEndTicks = { INT64_MIN }; - // Main data structure for storing function statistics to be shown in the popup windows. - // Uses the group name + region name as a key - just the region name does not suffice since there are collisions (ex. GarbageCollect) - AZStd::unordered_map m_regionStatisticsMap; - // Filter for highlighting regions on the visualizer - ImGuiTextFilter m_regionHighlightFilter; + ImGuiTextFilter m_visualizerHighlightFilter; }; } // namespace Render } // namespace AZ diff --git a/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.inl b/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.inl index 81fa440159..bb470f39e8 100644 --- a/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.inl +++ b/Gems/Atom/Utils/Code/Include/Atom/Utils/ImGuiCpuProfiler.inl @@ -17,11 +17,16 @@ #include #include +#pragma optimize("", off) + +#include "../../../Gems/ImGui/External/ImGui/v1.82/imgui/imgui.h" namespace AZ { namespace Render { + inline u64 TableRow::ms_frames = 0; + namespace CpuProfilerImGuiHelper { // NOTE: Fix build error in case AZStd::thread_id is not of an arithmetic type, and instead a pointer @@ -134,6 +139,92 @@ namespace AZ } } + inline void ImGuiCpuProfiler::DrawTable() + { + const auto flags = + ImGuiTableFlags_Borders | ImGuiTableFlags_Sortable | ImGuiTableFlags_Resizable | ImGuiTableFlags_Reorderable; + if (ImGui::BeginTable("FunctionStatisticsTable", 5, flags)) + { + // Table header setup + ImGui::TableSetupColumn("Group"); + ImGui::TableSetupColumn("Region"); + ImGui::TableSetupColumn("MTPC (ms)"); + ImGui::TableSetupColumn("Max (ms)"); + ImGui::TableSetupColumn("Invocations/frame"); + ImGui::TableHeadersRow(); + ImGui::TableNextColumn(); + + ImGuiTableSortSpecs* sortSpecs = ImGui::TableGetSortSpecs(); + if (sortSpecs && sortSpecs->SpecsDirty) + { + SortTable(sortSpecs); + } + + // Draw all of the rows held in the GroupRegionMap + for (const auto* statistics : m_tableData) + { + if (!m_timedRegionFilter.PassFilter(statistics->m_groupName.c_str()) + && !m_timedRegionFilter.PassFilter(statistics->m_regionName.c_str())) + { + continue; + } + + ImGui::Text(statistics->m_groupName.c_str()); + ImGui::TableNextColumn(); + + ImGui::Text(statistics->m_regionName.c_str()); + ImGui::TableNextColumn(); + + ImGui::Text("%.2f", CpuProfilerImGuiHelper::TicksToMs(statistics->m_runningAverageTicks)); + ImGui::TableNextColumn(); + + ImGui::Text("%.2f", CpuProfilerImGuiHelper::TicksToMs(statistics->m_maxTicks)); + ImGui::TableNextColumn(); + + ImGui::Text("%.1f", statistics->GetAverageInvocationsPerFrame()); + ImGui::TableNextColumn(); + } + } + ImGui::EndTable(); + } + + inline void ImGuiCpuProfiler::SortTable(ImGuiTableSortSpecs* sortSpecs) + { + const bool ascending = sortSpecs->Specs->SortDirection == ImGuiSortDirection_Ascending; + const ImS16 columnToSort = sortSpecs->Specs->ColumnIndex; + + switch (columnToSort) + { + case (0): // Sort by group name + AZStd::sort(m_tableData.begin(), m_tableData.end(), [ascending](const TableRow* lhs, const TableRow* rhs){ + return ascending ? lhs->m_groupName < rhs->m_groupName : lhs->m_groupName > rhs->m_groupName; + }); + break; + case (1): // Sort by region name + AZStd::sort(m_tableData.begin(), m_tableData.end(),[ascending](const TableRow* lhs, const TableRow* rhs){ + return ascending ? lhs->m_regionName < rhs->m_regionName : lhs->m_regionName > rhs->m_regionName; + }); + break; + case (2): // Sort by average time + AZStd::sort(m_tableData.begin(), m_tableData.end(), [ascending](const TableRow* lhs, const TableRow* rhs){ + return ascending ? lhs->m_runningAverageTicks < rhs->m_runningAverageTicks + : lhs->m_runningAverageTicks > rhs->m_runningAverageTicks; + }); + break; + case (3): // Sort by max time + AZStd::sort(m_tableData.begin(), m_tableData.end(), [ascending](const TableRow* lhs, const TableRow* rhs){ + return ascending ? lhs->m_maxTicks < rhs->m_maxTicks : lhs->m_maxTicks > rhs->m_maxTicks; + }); + break; + case (4): // Sort by invocations + AZStd::sort(m_tableData.begin(), m_tableData.end(), [ascending](const TableRow* lhs, const TableRow* rhs){ + return ascending ? lhs->m_invocations < rhs->m_invocations : lhs->m_invocations > rhs->m_invocations; + }); + break; + } + sortSpecs->SpecsDirty = false; + } + inline void ImGuiCpuProfiler::DrawStatisticsView() { DrawCommonHeader(); @@ -156,62 +247,6 @@ namespace AZ ImGui::NextColumn(); }; - const auto DrawRegionHoverMarker = [this, &ShowTimeInMs](AZStd::vector& entries) - { - if (ImGui::IsItemHovered()) - { - ImGui::BeginTooltip(); - ImGui::PushTextWrapPos(ImGui::GetFontSize() * 60.0f); - - for (ThreadRegionEntry& entry : entries) - { - ImGui::Text(CpuProfilerImGuiHelper::TextThreadId(entry.m_threadId.m_id).c_str()); - - const AZStd::sys_time_t elapsed = entry.m_endTick - entry.m_startTick; - ShowTimeInMs(elapsed); - ImGui::Separator(); - } - - ImGui::PopTextWrapPos(); - ImGui::EndTooltip(); - } - }; - - const auto ShowRegionRow = - [ticksPerSecond, &DrawRegionHoverMarker, - &ShowTimeInMs](const char* regionLabel, AZStd::vector regions, AZStd::sys_time_t duration) - { - // Draw the region label - ImGui::Text(regionLabel); - ImGui::NextColumn(); - - // Draw the thread count label - AZStd::sys_time_t totalTime = 0; - AZStd::set threads; - for (ThreadRegionEntry& entry : regions) // Find the thread count and total execution time for all threads - { - threads.insert(entry.m_threadId); - totalTime += entry.m_endTick - entry.m_startTick; - } - const AZStd::string threadLabel = AZStd::string::format("Threads: %u", static_cast(threads.size())); - ImGui::Text(threadLabel.c_str()); - DrawRegionHoverMarker(regions); - ImGui::NextColumn(); - - // Draw the overall invocation count - const AZStd::string invocationLabel = AZStd::string::format("Total calls: %u", static_cast(regions.size())); - ImGui::Text(invocationLabel.c_str()); - DrawRegionHoverMarker(regions); - ImGui::NextColumn(); - - // Draw the time labels (max and then total) - const AZStd::string timeLabel = AZStd::string::format( - "%.2f ms max, %.2f ms total", CpuProfilerImGuiHelper::TicksToMs(duration), - CpuProfilerImGuiHelper::TicksToMs(totalTime)); - ImGui::Text(timeLabel.c_str()); - ImGui::NextColumn(); - }; - if (ImGui::BeginChild("Statistics View", { 0, 0 }, true)) { // Set column settings. @@ -229,44 +264,21 @@ namespace AZ ImGui::Separator(); ImGui::Columns(1, "view", false); - m_timedRegionFilter.Draw("TimedRegion Filter"); - - // Draw the timed regions - if (ImGui::BeginChild("TimedRegions")) + m_timedRegionFilter.Draw("Filter"); + ImGui::SameLine(); + if (ImGui::Button("Clear Filter")) { - for (auto& timeRegionMapEntry : m_groupRegionMap) - { - // Draw the regions - if (ImGui::TreeNodeEx(timeRegionMapEntry.first.c_str(), ImGuiTreeNodeFlags_DefaultOpen)) - { - ImGui::Columns(4, "view", false); - ImGui::SetColumnWidth(0, 400.0f); - ImGui::SetColumnWidth(1, 100.0f); - ImGui::SetColumnWidth(2, 150.0f); - ImGui::SetColumnWidth(3, 240.0f); - - for (auto& region : timeRegionMapEntry.second) - { - // Calculate the region with the longest execution time - AZStd::sys_time_t threadExecutionElapsed = 0; - for (ThreadRegionEntry& entry : region.second) - { - const AZStd::sys_time_t elapsed = entry.m_endTick - entry.m_startTick; - threadExecutionElapsed = AZStd::max(threadExecutionElapsed, elapsed); - } - - // Only draw the TimedRegion rows when it passes the filter - if (m_timedRegionFilter.PassFilter(region.first.c_str())) - { - ShowRegionRow(region.first.c_str(), region.second, threadExecutionElapsed); - } - } - ImGui::Columns(1, "view", false); - ImGui::TreePop(); - } - } - ImGui::EndChild(); + m_timedRegionFilter.Clear(); } + ImGui::SameLine(); + if (ImGui::Button("Reset Table")) + { + m_tableData.clear(); + m_groupRegionMap.clear(); + TableRow::ms_frames = 0; + } + + DrawTable(); } } @@ -280,7 +292,7 @@ namespace AZ { ImGui::Columns(3, "Options", true); ImGui::SliderInt("Saved Frames", &m_framesToCollect, 10, 10000, "%d", ImGuiSliderFlags_AlwaysClamp | ImGuiSliderFlags_Logarithmic); - m_regionHighlightFilter.Draw("Find Region"); + m_visualizerHighlightFilter.Draw("Find Region"); ImGui::NextColumn(); @@ -372,7 +384,6 @@ namespace AZ baseRow += maxDepth + 1; // Next draw loop should start one row down } - DrawRegionStatistics(); DrawFrameBoundaries(); // Draw an invisible button to capture inputs @@ -432,9 +443,6 @@ namespace AZ // view is only holding data from the last frame, the memory overhead is minimal and gives us a faster redraw // compared to if we needed to transform the visualizer's data into the statistical format every frame. - // Clear the statistical view's cached entries - m_groupRegionMap.clear(); - // Get the latest TimeRegionMap const RHI::CpuProfiler::TimeRegionMap& timeRegionMap = RHI::CpuProfiler::Get()->GetTimeRegionMap(); @@ -461,14 +469,15 @@ namespace AZ // Also update the statistical view's data const AZStd::string& groupName = region.m_groupRegionName->m_groupName; - m_groupRegionMap[groupName][regionName].push_back( - { threadId, region.m_startTick, region.m_endTick }); - // Update running statistics if we want to record this region's data - if (m_regionStatisticsMap[region.m_groupRegionName].m_record) + if (!m_groupRegionMap[groupName].contains(regionName)) { - m_regionStatisticsMap[region.m_groupRegionName].RecordRegion(region); + m_groupRegionMap[groupName][regionName].m_groupName = groupName; + m_groupRegionMap[groupName][regionName].m_regionName = regionName; + m_tableData.push_back(&m_groupRegionMap[groupName][regionName]); } + + m_groupRegionMap[groupName][regionName].RecordRegion(region); } } @@ -523,7 +532,7 @@ namespace AZ inline void ImGuiCpuProfiler::DrawBlock(const TimeRegion& block, u64 targetRow) { // Don't draw anything if the user is searching for regions and this block doesn't pass the filter - if (!m_regionHighlightFilter.PassFilter(block.m_groupRegionName->m_regionName)) + if (!m_visualizerHighlightFilter.PassFilter(block.m_groupRegionName->m_regionName)) { return; } @@ -573,13 +582,14 @@ namespace AZ // Tooltip and block highlighting if (ImGui::IsMouseHoveringRect(startPoint, endPoint) && ImGui::IsWindowHovered()) { - // Open function statistics map on click + // Go to the statistics view when a region is clicked if (ImGui::IsMouseClicked(ImGuiMouseButton_Left)) { - const GroupRegionName* key = block.m_groupRegionName; - m_regionStatisticsMap[key].m_draw = true; + m_enableVisualizer = false; + const auto newFilter = AZStd::string(block.m_groupRegionName->m_regionName); + m_timedRegionFilter = ImGuiTextFilter(newFilter.c_str()); + m_timedRegionFilter.Build(); } - // Hovering outline drawList->AddRect(startPoint, endPoint, ImGui::GetColorU32({ 1, 1, 1, 1 }), 0.0, 0, 1.5); @@ -631,31 +641,6 @@ namespace AZ ImGui::GetWindowDrawList()->AddText({ wx + 10, wy + baseRow * RowHeight + 5 }, IM_COL32_WHITE, threadIdText.c_str()); } - inline void ImGuiCpuProfiler::DrawRegionStatistics() - { - for (auto& [groupRegionName, stat] : m_regionStatisticsMap) - { - if (stat.m_draw) - { - ImGui::SetNextWindowSize({300, 340}, ImGuiCond_FirstUseEver); - ImGui::Begin(groupRegionName->m_regionName, &stat.m_draw, 0); - - if (ImGui::Button(stat.m_record ? "Pause" : "Resume")) - { - stat.m_record = !stat.m_record; - } - - ImGui::Text("Invocations: %llu", stat.m_invocations); - ImGui::Text("Average time: %.3f ms", stat.CalcAverageTimeMs()); - - ImGui::Separator(); - - ImGui::ColorPicker4("Region color", &m_regionColorMap[groupRegionName].x); - ImGui::End(); - } - } - } - inline void ImGuiCpuProfiler::DrawFrameBoundaries() { ImDrawList* drawList = ImGui::GetWindowDrawList(); @@ -857,25 +842,26 @@ namespace AZ else { m_frameEndTicks.push_back(AZStd::GetTimeNowTicks()); + TableRow::ms_frames++; } } - // ----- RegionStatistics implementation ----- - - inline float RegionStatistics::CalcAverageTimeMs() const - { - if (m_invocations == 0) - { - return 0.0; - } - const double averageTicks = aznumeric_cast(m_totalTicks) / m_invocations; - return CpuProfilerImGuiHelper::TicksToMs(aznumeric_cast(averageTicks)); - } + // ---- TableRow impl ---- - inline void RegionStatistics::RecordRegion(const AZ::RHI::CachedTimeRegion& region) + inline void TableRow::RecordRegion(const AZ::RHI::CachedTimeRegion& region) { m_invocations++; - m_totalTicks += region.m_endTick - region.m_startTick; + const AZStd::sys_time_t deltaTime = AZStd::abs(region.m_endTick - region.m_startTick); + m_maxTicks = AZStd::max(m_maxTicks, deltaTime); + + // Standard running average algorithm + const auto newMean = m_runningAverageTicks + aznumeric_cast((deltaTime - m_runningAverageTicks) * 1.0 / m_invocations); + m_runningAverageTicks = newMean; + } + + inline double TableRow::GetAverageInvocationsPerFrame() const + { + return 1.0 * m_invocations / ms_frames; } } // namespace Render } // namespace AZ