diff --git a/sources/core/Stride.Core/Diagnostics/ChromeTracingProfileWriter.cs b/sources/core/Stride.Core/Diagnostics/ChromeTracingProfileWriter.cs index a42e7c622d..121e5642a3 100644 --- a/sources/core/Stride.Core/Diagnostics/ChromeTracingProfileWriter.cs +++ b/sources/core/Stride.Core/Diagnostics/ChromeTracingProfileWriter.cs @@ -18,14 +18,14 @@ public void Start(string outputPath, bool indentOutput = false) { var pid = Process.GetCurrentProcess().Id; - using FileStream fs = File.Create(outputPath); - using var writer = new Utf8JsonWriter(fs, options: new JsonWriterOptions { Indented = indentOutput }); + using FileStream fs = File.Create(outputPath, 1024*1024); + using var writer = new Utf8JsonWriter(fs, options: new JsonWriterOptions { Indented = indentOutput, SkipValidation = true }); JsonObject root = new JsonObject(); writer.WriteStartObject(); writer.WriteStartArray("traceEvents"); - + writer.WriteStartObject(); writer.WriteString("name", "thread_name"); writer.WriteString("ph", "M"); @@ -46,7 +46,7 @@ public void Start(string outputPath, bool indentOutput = false) writer.WriteEndObject(); await foreach (var e in eventReader.ReadAllAsync()) - { + { //gc scopes currently start at negative timestamps and should be filtered out, //because they don't represent durations. if (e.TimeStamp.Ticks < 0) @@ -72,10 +72,15 @@ public void Start(string outputPath, bool indentOutput = false) foreach (var (k,v) in e.Attributes) { writer.WriteString(k, v.ToString()); - } + } writer.WriteEndObject(); } writer.WriteEndObject(); + + if(writer.BytesPending >= 1024 * 1024) + { + await writer.FlushAsync(); + } } writer.WriteEndArray(); @@ -92,6 +97,7 @@ public void Stop() writerTask?.Wait(); } } + #nullable enable ChannelReader? eventReader; Task? writerTask; diff --git a/sources/engine/Stride.Engine/Profiling/GameProfilingSystem.cs b/sources/engine/Stride.Engine/Profiling/GameProfilingSystem.cs index 4be1ba0d0a..19ea491292 100644 --- a/sources/engine/Stride.Engine/Profiling/GameProfilingSystem.cs +++ b/sources/engine/Stride.Engine/Profiling/GameProfilingSystem.cs @@ -51,7 +51,7 @@ public class GameProfilingSystem : GameSystemBase private Color4 textColor = Color.LightGreen; private GameProfilingResults filteringMode; - private Task stringBuilderTask; + private Task asyncUpdateTask; private Size2 renderTargetSize; private ChannelReader profilerChannel; private PresentInterval? userPresentInterval; @@ -101,10 +101,6 @@ public GameProfilingSystem(IServiceRegistry registry) : base(registry) gcProfiler = new GcProfiling(); } - private readonly Stopwatch dumpTiming = Stopwatch.StartNew(); - - - private void UpdateProfilingStrings(bool containsMarks) { profilersStringBuilder.Clear(); @@ -191,92 +187,95 @@ private void UpdateProfilingStrings(bool containsMarks) } } + private async Task UpdateAsync() + { + while(Enabled) + { + //In Fps filtering mode wait until it is time to update the output. + await Task.Delay((int)RefreshTime).ConfigureAwait(false); + + using (Profiler.Begin(UpdateStringsKey)) + { + UpdateProfilingStrings(false); + } + + if (profilerChannel == null || profilerChannel.Completion.IsCompleted) + continue; + + //If we're subscribed to the Profiler (Cpu/Gpu mode) start receiving events. + //Control flow will only return here once the profilerChannel is closed. + await ReadEventsAsync(); + } + } + private async Task ReadEventsAsync() { var containsMarks = false; + Task delayTask = Task.Delay((int)RefreshTime); - //TODO: Untangle this a bit. Currently fps display (FilteringMode == GameProfilingResults.Fps) - // depends on the timer/update logic, but it does not actually need the profiling events. - - while (Enabled) + await foreach (var e in profilerChannel.ReadAllAsync()) { - if (dumpTiming.ElapsedMilliseconds > RefreshTime) + if (delayTask.IsCompleted) { using (Profiler.Begin(UpdateStringsKey)) { UpdateProfilingStrings(containsMarks); - dumpTiming.Restart(); + delayTask = Task.Delay((int)RefreshTime); containsMarks = false; } } - if (profilerChannel == null) + if (FilteringMode == GameProfilingResults.Fps) continue; - await foreach (var e in profilerChannel.ReadAllAsync()) - { - if (dumpTiming.ElapsedMilliseconds > RefreshTime) - { - using (Profiler.Begin(UpdateStringsKey)) - { - UpdateProfilingStrings(containsMarks); - dumpTiming.Restart(); - containsMarks = false; - } - } - - if (FilteringMode == GameProfilingResults.Fps) - continue; - - if (e.IsGPUEvent() && FilteringMode != GameProfilingResults.GpuEvents) - continue; - if (!e.IsGPUEvent() && FilteringMode != GameProfilingResults.CpuEvents) - continue; - - //gc profiling is a special case - if (e.Key == GcProfiling.GcMemoryKey) - { - gcMemoryStringBuilder.Clear(); - e.Message?.ToString(gcMemoryStringBuilder); - continue; - } + if (e.IsGPUEvent() && FilteringMode != GameProfilingResults.GpuEvents) + continue; + if (!e.IsGPUEvent() && FilteringMode != GameProfilingResults.CpuEvents) + continue; - if (e.Key == GcProfiling.GcCollectionCountKey) - { - gcCollectionsStringBuilder.Clear(); - e.Message?.ToString(gcCollectionsStringBuilder); - continue; - } + //gc profiling is a special case + if (e.Key == GcProfiling.GcMemoryKey) + { + gcMemoryStringBuilder.Clear(); + e.Message?.ToString(gcMemoryStringBuilder); + continue; + } - if (e.Key == GameProfilingKeys.GameDrawFPS && e.Type == ProfilingMessageType.End) - continue; + if (e.Key == GcProfiling.GcCollectionCountKey) + { + gcCollectionsStringBuilder.Clear(); + e.Message?.ToString(gcCollectionsStringBuilder); + continue; + } - ProfilingResult profilingResult; - if (!profilingResultsDictionary.TryGetValue(e.Key, out profilingResult)) - { - profilingResult.MinTime = TimeSpan.MaxValue; - } + if (e.Key == GameProfilingKeys.GameDrawFPS && e.Type == ProfilingMessageType.End) + continue; - if (e.Type == ProfilingMessageType.End) - { - ++profilingResult.Count; - profilingResult.AccumulatedTime += e.ElapsedTime; + ProfilingResult profilingResult; + if (!profilingResultsDictionary.TryGetValue(e.Key, out profilingResult)) + { + profilingResult.MinTime = TimeSpan.MaxValue; + } - if (e.ElapsedTime < profilingResult.MinTime) - profilingResult.MinTime = e.ElapsedTime; - if (e.ElapsedTime > profilingResult.MaxTime) - profilingResult.MaxTime = e.ElapsedTime; + if (e.Type == ProfilingMessageType.End) + { + ++profilingResult.Count; + profilingResult.AccumulatedTime += e.ElapsedTime; - profilingResult.Event = e; - } - else if (e.Type == ProfilingMessageType.Mark) - { - profilingResult.MarkCount++; - containsMarks = true; - } + if (e.ElapsedTime < profilingResult.MinTime) + profilingResult.MinTime = e.ElapsedTime; + if (e.ElapsedTime > profilingResult.MaxTime) + profilingResult.MaxTime = e.ElapsedTime; - profilingResultsDictionary[e.Key] = profilingResult; + profilingResult.Event = e; } + else if (e.Type == ProfilingMessageType.Mark) + { + profilingResult.MarkCount++; + containsMarks = true; + } + + profilingResultsDictionary[e.Key] = profilingResult; } } @@ -323,9 +322,9 @@ protected override void Destroy() Profiler.Unsubscribe(profilerChannel); - if (stringBuilderTask != null && !stringBuilderTask.IsCompleted) + if (asyncUpdateTask != null && !asyncUpdateTask.IsCompleted) { - stringBuilderTask.Wait(); + asyncUpdateTask.Wait(); } gcProfiler.Dispose(); @@ -439,9 +438,9 @@ public void EnableProfiling(bool excludeKeys = false, params ProfilingKey[] keys gcProfiler.Enable(); - if (stringBuilderTask == null || stringBuilderTask.IsCompleted) + if (asyncUpdateTask == null || asyncUpdateTask.IsCompleted) { - stringBuilderTask = Task.Run(ReadEventsAsync); + asyncUpdateTask = Task.Run(UpdateAsync); } }