From c2700ccd10a20e699f7a182f587955a33d500bc1 Mon Sep 17 00:00:00 2001 From: RDW Date: Thu, 25 Jan 2024 01:06:11 +0100 Subject: [PATCH 1/3] Refactor: Enable arbitrary number formats for performance metrics The code originally assumes time (in milliseconds), which doesn't allow for displaying RAM usage or other metrics. Since time is a sensible default, overriding the format for specific items seems generalized enough for now. A better approach might be to allow passing formatter functions and using tables instead of varargs (to be order-independent). But it's probably not needed, so defer until there's a reason to generalize further. --- .../Interface/PerformanceMetricsOverlay.lua | 4 +++- .../PerformanceMetricsOverlay.spec.lua | 23 +++++++++++++++++++ 2 files changed, 26 insertions(+), 1 deletion(-) diff --git a/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua b/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua index d838f9fe..6c1a85c9 100644 --- a/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua +++ b/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua @@ -5,6 +5,7 @@ local tinsert = table.insert local PerformanceMetricsOverlay = { samples = {}, + formatOverrides = {}, isEnabled = false, messageStrings = { NO_SAMPLES_AVAILABLE = "No performance metrics available at this time", @@ -53,7 +54,8 @@ function PerformanceMetricsOverlay:GetFormattedMetricsString() local isLastMetric = (index == #self.samples) local separator = isLastMetric and "" or " | " - tinsert(sampleStrings, format("%s: %.2f ms%s", name, avg, separator)) + local formatString = self.formatOverrides[name] or "%s: %.2f ms%s" + tinsert(sampleStrings, format(formatString, name, avg, separator)) end return tconcat(sampleStrings, "") diff --git a/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua b/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua index db404b79..c3973e1c 100644 --- a/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua +++ b/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua @@ -90,5 +90,28 @@ describe("PerformanceMetricsOverlay", function() "totalFrameTime: 100.00 ms | cpuRenderTime: nan ms | worldRenderTime: 200.00 ms | interfaceRenderTime: 300.00 ms | commandSubmissionTime: 600.00 ms | uvPollingTime: 400.00 ms | glfwPollingTime: 500.00 ms" assertEquals(actual, expected) end) + + it("should allow overriding the format for non-standard types of metrics", function() + PerformanceMetricsOverlay:StartMeasuring() + + local metricsEntry = { + Memory = 1024, + Percentage = 56.75345, + Time = 250, + "Memory", + "Percentage", + "Time", + } + PerformanceMetricsOverlay:AddSample(metricsEntry) + PerformanceMetricsOverlay:AddSample(metricsEntry) + + PerformanceMetricsOverlay.formatOverrides.Memory = "%s: %d MB%s" + PerformanceMetricsOverlay.formatOverrides.Percentage = "%s: %.2f %%%s" + PerformanceMetricsOverlay.formatOverrides.Time = "%s: %d milliseconds%s" + + local actual = PerformanceMetricsOverlay:GetFormattedMetricsString() + local expected = "Memory: 1024 MB | Percentage: 56.75 % | Time: 250 milliseconds" + assertEquals(actual, expected) + end) end) end) From 7a571744b49f7c6ffe885d986557c1c812ae949c Mon Sep 17 00:00:00 2001 From: RDW Date: Thu, 25 Jan 2024 01:09:41 +0100 Subject: [PATCH 2/3] UI: Add memory usage to the performance metrics display --- Core/NativeClient/NativeClient.lua | 3 +++ 1 file changed, 3 insertions(+) diff --git a/Core/NativeClient/NativeClient.lua b/Core/NativeClient/NativeClient.lua index 99f29680..124deef9 100644 --- a/Core/NativeClient/NativeClient.lua +++ b/Core/NativeClient/NativeClient.lua @@ -87,6 +87,7 @@ function NativeClient:CreateMainWindow() end function NativeClient:StartRenderLoop() + PerformanceMetricsOverlay.formatOverrides.Memory = "%s: %d MB%s" PerformanceMetricsOverlay:StartMeasuring() -- Should probably replace with RML data binding or a similar approach later? @@ -116,6 +117,7 @@ function NativeClient:StartRenderLoop() local frameTimeInMilliseconds = (frameEndTime - frameStartTime) / 10E5 local sample = { + Memory = collectgarbage("count") / 1024, Frame = frameTimeInMilliseconds, Render = cpuFrameTime / 10E5, World = worldRenderTime / 10E5, @@ -123,6 +125,7 @@ function NativeClient:StartRenderLoop() Submit = commandSubmissionTime / 10E5, UV = uvPollingTime / 10E5, GLFW = (glfwPollingTime + replayTime) / 10E5, + "Memory", "Frame", "Render", "World", From 5a692f941b397f648b701c33e9a5444e3be92ee9 Mon Sep 17 00:00:00 2001 From: RDW Date: Thu, 25 Jan 2024 01:26:45 +0100 Subject: [PATCH 3/3] UI: Add CPU time to the performance metrics display This isn't necessarily accurate due to multithreading concerns. While it serves to detect performance outliers, it's not indicative of the actual system load (by design). --- .../Interface/PerformanceMetricsOverlay.lua | 22 ++++++ Core/NativeClient/NativeClient.lua | 13 ++++ .../PerformanceMetricsOverlay.spec.lua | 74 +++++++++++++++++++ 3 files changed, 109 insertions(+) diff --git a/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua b/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua index 6c1a85c9..49ed5b7d 100644 --- a/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua +++ b/Core/NativeClient/Interface/PerformanceMetricsOverlay.lua @@ -61,4 +61,26 @@ function PerformanceMetricsOverlay:GetFormattedMetricsString() return tconcat(sampleStrings, "") end +local function toMicroseconds(time) + return time.sec * 1E6 + time.usec +end + +function PerformanceMetricsOverlay:ComputeResourceUsageForInterval( + initialResourceUsage, + finalUsage, + measuredIntervalInMilliseconds +) + if measuredIntervalInMilliseconds <= 0 then + return 0 + end + + local initialTotal = toMicroseconds(initialResourceUsage.utime) + local finalTotal = toMicroseconds(finalUsage.utime) + + local cpuTimeUsedInMicroseconds = finalTotal - initialTotal + local elapsedTimeInMicroseconds = measuredIntervalInMilliseconds * 1E3 + + return (cpuTimeUsedInMicroseconds / elapsedTimeInMicroseconds) * 100 +end + return PerformanceMetricsOverlay diff --git a/Core/NativeClient/NativeClient.lua b/Core/NativeClient/NativeClient.lua index 124deef9..5312a8e0 100644 --- a/Core/NativeClient/NativeClient.lua +++ b/Core/NativeClient/NativeClient.lua @@ -87,8 +87,10 @@ function NativeClient:CreateMainWindow() end function NativeClient:StartRenderLoop() + PerformanceMetricsOverlay.formatOverrides.CPU = "%s: %.2f %%%s" PerformanceMetricsOverlay.formatOverrides.Memory = "%s: %d MB%s" PerformanceMetricsOverlay:StartMeasuring() + local initialResourceUsage = uv.getrusage() -- Should probably replace with RML data binding or a similar approach later? self.fpsDisplayTicker = C_Timer.NewTicker(2500, function() @@ -116,7 +118,17 @@ function NativeClient:StartRenderLoop() local frameEndTime = uv.hrtime() local frameTimeInMilliseconds = (frameEndTime - frameStartTime) / 10E5 + local lastMeasuredResourceUsage = uv.getrusage() + + local cpuUsage = PerformanceMetricsOverlay:ComputeResourceUsageForInterval( + initialResourceUsage, + lastMeasuredResourceUsage, + frameTimeInMilliseconds + ) + initialResourceUsage = lastMeasuredResourceUsage + local sample = { + CPU = cpuUsage, Memory = collectgarbage("count") / 1024, Frame = frameTimeInMilliseconds, Render = cpuFrameTime / 10E5, @@ -126,6 +138,7 @@ function NativeClient:StartRenderLoop() UV = uvPollingTime / 10E5, GLFW = (glfwPollingTime + replayTime) / 10E5, "Memory", + "CPU", "Frame", "Render", "World", diff --git a/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua b/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua index c3973e1c..4c677d13 100644 --- a/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua +++ b/Tests/NativeClient/Interface/PerformanceMetricsOverlay.spec.lua @@ -113,5 +113,79 @@ describe("PerformanceMetricsOverlay", function() local expected = "Memory: 1024 MB | Percentage: 56.75 % | Time: 250 milliseconds" assertEquals(actual, expected) end) + + describe("ComputeResourceUsageForInterval", function() + local function uvMakeResourceUsage(seconds, microseconds) + return { + utime = { sec = seconds, usec = microseconds }, + stime = { sec = 0, usec = 0 }, -- stime is ignored since it may be async background tasks etc. + } + end + + it("should compute the resource usage if the measured interval is zero", function() + local initialUsage = uvMakeResourceUsage(1, 500000) -- 1.5 seconds + local finalUsage = uvMakeResourceUsage(1, 500000) -- 1.5 seconds + local measuredIntervalInMilliseconds = 0 -- 1 second + local expected = 0 + local actual = PerformanceMetricsOverlay:ComputeResourceUsageForInterval( + initialUsage, + finalUsage, + measuredIntervalInMilliseconds + ) + assertEquals(actual, expected) + end) + + it("should compute the resource usage correctly if it's 0%", function() + local initialUsage = uvMakeResourceUsage(1, 500000) -- 1.5 seconds + local finalUsage = uvMakeResourceUsage(1, 500000) -- 1.5 seconds + local measuredIntervalInMilliseconds = 1000 -- 1 second + local expected = 0 + local actual = PerformanceMetricsOverlay:ComputeResourceUsageForInterval( + initialUsage, + finalUsage, + measuredIntervalInMilliseconds + ) + assertEquals(actual, expected) + end) + + it("should compute the resource usage correctly if it's 100%", function() + local initialUsage = uvMakeResourceUsage(0, 500000) -- 0.5 seconds + local finalUsage = uvMakeResourceUsage(1, 0) -- 1 second + local measuredIntervalInMilliseconds = 500 -- 0.5 second + local expected = 100 -- 100% CPU usage + local actual = PerformanceMetricsOverlay:ComputeResourceUsageForInterval( + initialUsage, + finalUsage, + measuredIntervalInMilliseconds + ) + assertEquals(actual, expected) + end) + + it("should compute the resource usage correctly if it's more than 100%", function() + local initialUsage = uvMakeResourceUsage(0, 500000) -- 0.5 seconds + local finalUsage = uvMakeResourceUsage(2, 0) -- 1 second + local measuredIntervalInMilliseconds = 500 -- 0.5 second + local expected = 300 -- 300% CPU usage (probably a measurement error or timer inaccuracy - ignore it) + local actual = PerformanceMetricsOverlay:ComputeResourceUsageForInterval( + initialUsage, + finalUsage, + measuredIntervalInMilliseconds + ) + assertEquals(actual, expected) + end) + + it("should compute the resource usage correctly over the provided duration", function() + local initialUsage = uvMakeResourceUsage(1, 0) -- 1 second + local finalUsage = uvMakeResourceUsage(2, 0) -- 2 seconds + local measuredIntervalInMilliseconds = 2000 -- 2 seconds + local expected = 50 -- 50% CPU usage + local actual = PerformanceMetricsOverlay:ComputeResourceUsageForInterval( + initialUsage, + finalUsage, + measuredIntervalInMilliseconds + ) + assertEquals(actual, expected) + end) + end) end) end)