From 82fe47f627baa015e33d578fbeedfce0fcc8a330 Mon Sep 17 00:00:00 2001 From: max Date: Sat, 19 Oct 2024 23:41:05 +0200 Subject: [PATCH] Profiler and LocalToWorldThreadedSystem Added a simple profiler Testing LocalToWorldSystem with Parallel execution for root nodes --- Nerfed.Editor/Program.cs | 34 ++++- .../Systems/EditorHierarchyWindow.cs | 2 +- Nerfed.Editor/Systems/EditorProfilerWindow.cs | 123 ++++++++++++++++++ Nerfed.Runtime/Engine.cs | 14 ++ Nerfed.Runtime/Profiler.cs | 115 +++++++++++++++- Nerfed.Runtime/Systems/LocalToWorldSystem.cs | 9 +- .../Systems/LocalToWorldThreadedSystem.cs | 81 ++++++++++++ Nerfed.Runtime/Util/BoundedQueue.cs | 73 +++++++++++ 8 files changed, 434 insertions(+), 17 deletions(-) create mode 100644 Nerfed.Editor/Systems/EditorProfilerWindow.cs create mode 100644 Nerfed.Runtime/Systems/LocalToWorldThreadedSystem.cs create mode 100644 Nerfed.Runtime/Util/BoundedQueue.cs diff --git a/Nerfed.Editor/Program.cs b/Nerfed.Editor/Program.cs index a5d46b0..676c99e 100644 --- a/Nerfed.Editor/Program.cs +++ b/Nerfed.Editor/Program.cs @@ -28,6 +28,8 @@ private static void HandleOnInitialize() { //systems.Add(new ParentSystem(world)); systems.Add(new LocalToWorldSystem(world)); + systems.Add(new LocalToWorldThreadedSystem(world)); + editorSystems.Add(new EditorProfilerWindow(world)); editorSystems.Add(new EditorHierarchyWindow(world)); Entity ent1 = world.CreateEntity("parent"); @@ -47,6 +49,20 @@ private static void HandleOnInitialize() Entity ent5 = world.CreateBaseEntity("entity5"); + for (int i = 0; i < 10; i++) + { + Entity newEnt = world.CreateBaseEntity(); + world.Set(newEnt, new LocalTransform(new Vector3(i, i, i), Quaternion.Identity, Vector3.One)); + + Entity parent = newEnt; + for (int j = 0; j < 10; j++) { + Entity newChildEnt = world.CreateEntity(); + world.Set(newChildEnt, new LocalTransform(new Vector3(j, j, j), Quaternion.Identity, Vector3.One)); + Transform.SetParent(world, newChildEnt, parent); + parent = newChildEnt; + } + } + // Open project. // Setip EditorGui. EditorGui.Initialize(); @@ -56,16 +72,24 @@ private static void HandleOnUpdate() { foreach (MoonTools.ECS.System system in systems) { - system.Update(Engine.Timestep); + using (new ProfilerScope(system.GetType().Name)) + { + system.Update(Engine.Timestep); + } } - // Editor Update. - EditorGui.Update(); - + using (new ProfilerScope("EditorGui.Update")) + { + // Editor Update. + EditorGui.Update(); + } // Try Catch UserCode Update. - world.FinishUpdate(); + using (new ProfilerScope("world.FinishUpdate")) + { + world.FinishUpdate(); + } } private static void HandleOnRender() diff --git a/Nerfed.Editor/Systems/EditorHierarchyWindow.cs b/Nerfed.Editor/Systems/EditorHierarchyWindow.cs index f300951..4cbda6d 100644 --- a/Nerfed.Editor/Systems/EditorHierarchyWindow.cs +++ b/Nerfed.Editor/Systems/EditorHierarchyWindow.cs @@ -8,7 +8,7 @@ namespace Nerfed.Editor.Systems { // Window that draws entities. - internal class EditorHierarchyWindow : MoonTools.ECS.DebugSystem + internal class EditorHierarchyWindow : MoonTools.ECS.System { private const ImGuiTreeNodeFlags baseFlags = ImGuiTreeNodeFlags.OpenOnArrow | ImGuiTreeNodeFlags.OpenOnDoubleClick | ImGuiTreeNodeFlags.SpanAvailWidth; diff --git a/Nerfed.Editor/Systems/EditorProfilerWindow.cs b/Nerfed.Editor/Systems/EditorProfilerWindow.cs new file mode 100644 index 0000000..ec67b54 --- /dev/null +++ b/Nerfed.Editor/Systems/EditorProfilerWindow.cs @@ -0,0 +1,123 @@ +using ImGuiNET; +using MoonTools.ECS; +using Nerfed.Runtime; +using System; + +namespace Nerfed.Editor.Systems +{ + internal class EditorProfilerWindow : MoonTools.ECS.System + { + const ImGuiTableFlags tableFlags = ImGuiTableFlags.Resizable | ImGuiTableFlags.BordersOuter | ImGuiTableFlags.NoBordersInBody | ImGuiTableFlags.ScrollY | ImGuiTableFlags.ScrollX; + const ImGuiTreeNodeFlags treeNodeFlags = ImGuiTreeNodeFlags.SpanAllColumns; + const ImGuiTreeNodeFlags treeNodeLeafFlags = ImGuiTreeNodeFlags.SpanAllColumns | ImGuiTreeNodeFlags.Leaf | ImGuiTreeNodeFlags.NoTreePushOnOpen; + + int frame = 0; + + public EditorProfilerWindow(World world) : base(world) + { + } + + public override void Update(TimeSpan delta) + { + if (Profiler.frames.Count <= 0) + { + return; + } + + ImGui.Begin("Profiler"); + + ImGui.BeginChild("Toolbar", new System.Numerics.Vector2(0, 0), ImGuiChildFlags.AutoResizeY); + if (ImGui.RadioButton("Recording", Profiler.recording)) + { + Profiler.recording = !Profiler.recording; + } + + ImGui.SameLine(); + + if (Profiler.recording) + { + frame = Profiler.frames.Count - 1; + } + if (ImGui.SliderInt(string.Empty, ref frame, 0, Profiler.frames.Count - 1)) + { + Profiler.recording = false; + } + + Profiler.FrameData frameData = Profiler.frames.ElementAt(frame); + double ms = frameData.ElapsedMilliseconds(); + double s = 1000; + ImGui.Text($"Frame: {frameData.frame} ({ms:0.000} ms | {(s / ms):0} fps)"); + ImGui.EndChild(); + + ImGui.BeginChild("Hierachy", new System.Numerics.Vector2(150, 0), ImGuiChildFlags.ResizeX); + + if (ImGui.BeginTable("ProfilerData", 2, tableFlags, new System.Numerics.Vector2(0, 0))) + { + ImGui.TableSetupColumn("name", ImGuiTableColumnFlags.WidthStretch, 0.8f, 0); + ImGui.TableSetupColumn("ms", ImGuiTableColumnFlags.WidthStretch, 0.2f, 1); + ImGui.TableSetupScrollFreeze(0, 1); // Make row always visible + ImGui.TableHeadersRow(); + + foreach (Profiler.ProfileRecord record in frameData.records) + { + ImGui.TableNextRow(); + ImGui.TableNextColumn(); + string indentation = new string(' ', record.depth); // Indentation based on depth + ImGui.Text($"{indentation}{record.label}"); + ImGui.TableNextColumn(); + ImGui.Text($"{record.ElapsedMilliseconds():0.000}"); + } + + ImGui.EndTable(); + } + + ImGui.EndChild(); + + ImGui.SameLine(); + + ImGui.BeginChild("Combined", new System.Numerics.Vector2(0, 0)); + + // Gather combined data. + Dictionary combinedRecordData = new Dictionary(128); + foreach (Profiler.ProfileRecord record in frameData.records) + { + if (combinedRecordData.TryGetValue(record.label, out double totalMs)) + { + combinedRecordData[record.label] = totalMs + record.ElapsedMilliseconds(); + } + else + { + combinedRecordData.Add(record.label, record.ElapsedMilliseconds()); + } + } + IOrderedEnumerable> orderedCombinedData = combinedRecordData.OrderByDescending(x => x.Value); + + if (ImGui.BeginTable("ProfilerCombinedData", 2, tableFlags, new System.Numerics.Vector2(0, 0))) + { + ImGui.TableSetupColumn("name", ImGuiTableColumnFlags.WidthStretch, 0.8f, 0); + ImGui.TableSetupColumn("ms", ImGuiTableColumnFlags.WidthStretch, 0.2f, 1); + ImGui.TableSetupScrollFreeze(0, 1); // Make row always visible + ImGui.TableHeadersRow(); + + foreach (KeyValuePair combinedData in orderedCombinedData) + { + ImGui.TableNextRow(); + ImGui.TableNextColumn(); + ImGui.Text($"{combinedData.Key}"); + ImGui.TableNextColumn(); + ImGui.Text($"{combinedData.Value:0.000}"); + } + + ImGui.EndTable(); + } + + ImGui.EndChild(); + ImGui.End(); + } + + private void Draw() + { + + } + } +} diff --git a/Nerfed.Runtime/Engine.cs b/Nerfed.Runtime/Engine.cs index 80f114e..3a7e894 100644 --- a/Nerfed.Runtime/Engine.cs +++ b/Nerfed.Runtime/Engine.cs @@ -111,10 +111,14 @@ public static void Quit() private static void Tick() { + Profiler.BeginFrame(); + AdvanceElapsedTime(); if (framerateCapped) { + Profiler.BeginSample("framerateCapped"); + /* We want to wait until the framerate cap, * but we don't want to oversleep. Requesting repeated 1ms sleeps and * seeing how long we actually slept for lets us estimate the worst case @@ -137,6 +141,8 @@ private static void Tick() Thread.SpinWait(1); AdvanceElapsedTime(); } + + Profiler.EndSample(); } // Do not let any step take longer than our maximum. @@ -149,6 +155,7 @@ private static void Tick() { while (accumulatedUpdateTime >= Timestep) { + Profiler.BeginSample("Update"); Keyboard.Update(); Mouse.Update(); GamePad.Update(); @@ -156,19 +163,26 @@ private static void Tick() ProcessSDLEvents(); // Tick game here... + Profiler.BeginSample("OnUpdate"); OnUpdate?.Invoke(); + Profiler.EndSample(); AudioDevice.WakeThread(); accumulatedUpdateTime -= Timestep; + Profiler.EndSample(); } double alpha = accumulatedUpdateTime / Timestep; // Render here.. + Profiler.BeginSample("OnRender"); OnRender?.Invoke(); + Profiler.EndSample(); accumulatedDrawTime -= framerateCapTimeSpan; } + + Profiler.EndFrame(); } private static TimeSpan AdvanceElapsedTime() diff --git a/Nerfed.Runtime/Profiler.cs b/Nerfed.Runtime/Profiler.cs index 5959d99..07fad5a 100644 --- a/Nerfed.Runtime/Profiler.cs +++ b/Nerfed.Runtime/Profiler.cs @@ -1,6 +1,4 @@ using System.Diagnostics; -using System.Reflection; -using System.Runtime.CompilerServices; namespace Nerfed.Runtime; @@ -17,13 +15,120 @@ public void Dispose() { public static class Profiler { - [Conditional("PROFILING")] - public static void BeginSample(string label) { + public struct ProfileRecord + { + public string label; + public long startTime; + public long endTime; + public int depth; + public readonly double ElapsedMilliseconds() + { + long elapsedTicks = endTime - startTime; + return ((double)(elapsedTicks * 1000)) / Stopwatch.Frequency; + } + } + + public class FrameData + { + public uint frame; + public readonly List records = new List(); + public long startTime; + public long endTime; + + public FrameData(uint frame, long startTime) + { + this.frame = frame; + this.startTime = startTime; + } + + public double ElapsedMilliseconds() + { + long elapsedTicks = endTime - startTime; + return ((double)(elapsedTicks * 1000)) / Stopwatch.Frequency; + } + } + + private const int maxFrames = 128; + + public static readonly BoundedQueue frames = new(maxFrames); + public static bool recording = true; + + private static readonly Stopwatch stopwatch = new Stopwatch(); + private static FrameData currentFrame = null; + private static uint currentFrameIndex = 0; + private static int currentDepth = 0; + + static Profiler() + { + stopwatch.Start(); } [Conditional("PROFILING")] - public static void EndSample() { + public static void BeginFrame() + { + if (!recording) + { + return; + } + currentFrame = new FrameData(currentFrameIndex, stopwatch.ElapsedTicks); + currentDepth = 0; + currentFrameIndex++; + } + + [Conditional("PROFILING")] + public static void EndFrame() + { + if (!recording) + { + return; + } + + currentFrame.endTime = stopwatch.ElapsedTicks; + frames.Enqueue(currentFrame); + } + + [Conditional("PROFILING")] + public static void BeginSample(string label) + { + if (!recording) + { + return; + } + + ProfileRecord record = new ProfileRecord + { + label = label, + startTime = stopwatch.ElapsedTicks, + depth = currentDepth, + }; + currentFrame.records.Add(record); + //Log.Info($"{record.label} {record.depth} | {record.startTime}"); + currentDepth++; // Increase depth for nested scopes + } + + [Conditional("PROFILING")] + public static void EndSample() + { + if (!recording) + { + return; + } + + currentDepth--; // Decrease depth when exiting a scope + + // Find the last uncompleted record at the current depth and set the end time + for (int i = currentFrame.records.Count - 1; i >= 0; i--) + { + if (currentFrame.records[i].endTime == 0) + { + ProfileRecord record = currentFrame.records[i]; + record.endTime = stopwatch.ElapsedTicks; + currentFrame.records[i] = record; // Assign back to the list + //Log.Info($"{record.label} | {record.depth} | {record.endTime}"); + break; + } + } } } \ No newline at end of file diff --git a/Nerfed.Runtime/Systems/LocalToWorldSystem.cs b/Nerfed.Runtime/Systems/LocalToWorldSystem.cs index 33bf06c..0be511b 100644 --- a/Nerfed.Runtime/Systems/LocalToWorldSystem.cs +++ b/Nerfed.Runtime/Systems/LocalToWorldSystem.cs @@ -24,11 +24,9 @@ public LocalToWorldSystem(World world) : base(world) public override void Update(TimeSpan delta) { - Matrix4x4 rootMatrix = Matrix4x4.Identity; - foreach (Entity entity in rootEntitiesFilter.Entities) { - UpdateWorldTransform(entity, rootMatrix); + UpdateWorldTransform(entity, Matrix4x4.Identity); } } @@ -37,18 +35,17 @@ private void UpdateWorldTransform(in Entity entity, Matrix4x4 localToWorldMatrix // TODO: Only update dirty transforms. // If a parent is dirty all the children need to update their localToWorld matrix. // How do we check if something is dirty? How do we know if a LocalTransform has been changed? - if (Has(entity)) { LocalTransform localTransform = Get(entity); localToWorldMatrix = Matrix4x4.Multiply(localToWorldMatrix, localTransform.TRS()); LocalToWorld localToWorld = new(localToWorldMatrix); Set(entity, localToWorld); - + //Task.Delay(10).Wait(); //Log.Info($"Entity {entity} | local position {localTransform.position} | world position {localToWorldMatrix.Translation}"); } - ReverseSpanEnumerator childEntities = World.OutRelations(entity); + ReverseSpanEnumerator childEntities = World.InRelations(entity); foreach (Entity childEntity in childEntities) { UpdateWorldTransform(childEntity, localToWorldMatrix); diff --git a/Nerfed.Runtime/Systems/LocalToWorldThreadedSystem.cs b/Nerfed.Runtime/Systems/LocalToWorldThreadedSystem.cs new file mode 100644 index 0000000..d0cbe05 --- /dev/null +++ b/Nerfed.Runtime/Systems/LocalToWorldThreadedSystem.cs @@ -0,0 +1,81 @@ +using MoonTools.ECS; +using Nerfed.Runtime.Components; +using Nerfed.Runtime.Util; +using System.Numerics; + +namespace Nerfed.Runtime.Systems +{ + public class LocalToWorldThreadedSystem : MoonTools.ECS.System + { + private readonly Filter rootEntitiesFilter; + private readonly Action forEntity; + + public LocalToWorldThreadedSystem(World world) : base(world) + { + rootEntitiesFilter = FilterBuilder.Include().Exclude().Build(); + forEntity = UpdateEntity; + } + + public override void Update(TimeSpan delta) + { + Parallel.For(0, rootEntitiesFilter.Count, forEntity); + } + + private void UpdateEntity(int entityFilterIndex) + { + Entity entity = rootEntitiesFilter.NthEntity(entityFilterIndex); + UpdateWorldTransform(entity, Matrix4x4.Identity); + } + + private void UpdateWorldTransform(Entity entity, Matrix4x4 localToWorldMatrix) + { + // TODO: Only update dirty transforms. + // If a parent is dirty all the children need to update their localToWorld matrix. + // How do we check if something is dirty? How do we know if a LocalTransform has been changed? + + if (Has(entity)) + { + LocalTransform localTransform = Get(entity); + localToWorldMatrix = Matrix4x4.Multiply(localToWorldMatrix, localTransform.TRS()); + LocalToWorld localToWorld = new(localToWorldMatrix); + Set(entity, localToWorld); + //Task.Delay(10).Wait(); + //Log.Info($"Entity {entity} | local position {localTransform.position} | world position {localToWorldMatrix.Translation}"); + } + + ReverseSpanEnumerator childEntities = World.InRelations(entity); + foreach (Entity childEntity in childEntities) + { + UpdateWorldTransform(childEntity, localToWorldMatrix); + } + } + } +} + + +//System.Random rnd = new System.Random(); + +//World world = new World(); +//Filter filter = world.FilterBuilder.Include().Build(); + +//for (int i = 0; i < 100; i++) +//{ +// Entity e = world.CreateEntity(i.ToString()); +// world.Set(e, new Test()); +//} + +//Action forEntityIndex = ForEntityIndex; +//ParallelLoopResult result = Parallel.For(0, filter.Count, forEntityIndex); +//Console.WriteLine(result.IsCompleted); + +//void ForEntityIndex(int entity) +//{ +// int delay = rnd.Next(1, 1000); +// Task.Delay(delay).Wait(); +// Console.WriteLine($"ForEntityIndex | {filter.NthEntity(entity).ID}"); +//} + +//namespace Hoi +//{ +// public readonly record struct Test; +//} \ No newline at end of file diff --git a/Nerfed.Runtime/Util/BoundedQueue.cs b/Nerfed.Runtime/Util/BoundedQueue.cs new file mode 100644 index 0000000..e354dae --- /dev/null +++ b/Nerfed.Runtime/Util/BoundedQueue.cs @@ -0,0 +1,73 @@ +using System.Collections; + +namespace Nerfed.Runtime; + +public class BoundedQueue : IEnumerable, ICollection, IReadOnlyCollection +{ + private readonly Queue queue = null; + private readonly int maxSize = 10; + private T lastAddedElement; + + public BoundedQueue(int maxSize) + { + this.maxSize = maxSize; + queue = new Queue(maxSize); + } + + public void Enqueue(T item) + { + queue.Enqueue(item); + if (queue.Count > maxSize) + { + queue.Dequeue(); // Remove the oldest element + } + + lastAddedElement = item; + } + + public T Dequeue() + { + return queue.Dequeue(); + } + + public T Peek() + { + return queue.Peek(); + } + + public T LastAddedElement() + { + return lastAddedElement; + } + + public void Clear() + { + queue.Clear(); + } + + public bool Contains(T item) + { + return queue.Contains(item); + } + + public IEnumerator GetEnumerator() + { + return queue.GetEnumerator(); + } + + IEnumerator IEnumerable.GetEnumerator() + { + return queue.GetEnumerator(); + } + + public void CopyTo(Array array, int index) + { + ((ICollection)queue).CopyTo(array, index); + } + + public int Count => queue.Count; + public int Capacity => maxSize; + public bool IsSynchronized => ((ICollection)queue).IsSynchronized; + public object SyncRoot => ((ICollection)queue).SyncRoot; + int IReadOnlyCollection.Count => queue.Count; +} \ No newline at end of file