// Copyright (c) 2012-2023 Wojciech Figat. All rights reserved. using System; using System.IO; using System.Collections.Generic; using System.Text; using System.Threading; using System.Diagnostics; namespace Flax.Build { /// /// Inserts a profiling event for the given code scope. /// public class ProfileEventScope : IDisposable { private readonly int _id; /// /// Initializes a new instance of the class. /// /// The event name. public ProfileEventScope(string name) { _id = Profiling.Begin(name); } /// /// Ends the profiling event. /// public void Dispose() { Profiling.End(_id); } } /// /// The build system performance profiling tools. /// public static class Profiling { /// /// The performance event data. /// public struct Event { /// /// The event name. /// public string Name; /// /// The event start time. /// public DateTime StartTime; /// /// The event duration. /// public TimeSpan Duration; /// /// The event call depth (for parent-children events evaluation). /// public int Depth; /// /// The calling thread id. /// public int ThreadId; } private static int _depth; private static readonly List _events = new List(1024); private static readonly DateTime _startTime = DateTime.Now; private static readonly Stopwatch _stopwatch = Stopwatch.StartNew(); // https://stackoverflow.com/questions/1416139/how-to-get-timestamp-of-tick-precision-in-net-c /// /// Begins the profiling event. /// /// The name. /// The event id. Used by callback. public static int Begin(string name) { Event e; e.Name = name; e.StartTime = _startTime.AddTicks(_stopwatch.Elapsed.Ticks); e.Duration = TimeSpan.Zero; e.Depth = _depth++; e.ThreadId = Thread.CurrentThread.ManagedThreadId; _events.Add(e); return _events.Count - 1; } /// /// Ends the profiling event. /// /// The event identifier returned by . public static void End(int id) { var endTime = _startTime.AddTicks(_stopwatch.Elapsed.Ticks); var e = _events[id]; e.Duration = endTime - e.StartTime; _events[id] = e; _depth--; } /// /// Logs the recorded profiler events. /// public static void LogStats() { TimeSpan add = TimeSpan.Zero; for (int i = 0; i < _events.Count; i++) { var e = _events[i]; if (i + 1 < _events.Count && _events[i + 1].Depth == e.Depth && _events[i + 1].Name == e.Name) { // Merge two events times add += e.Duration; continue; } string str = string.Empty; while (e.Depth-- > 0) str += " "; str += e.Name; str += " "; str += e.Duration + add; add = TimeSpan.Zero; Log.Info(str); } } /// /// Generates the Trace Event file for profiling build system events. /// public static void GenerateTraceEventFile() { var traceEventFile = Configuration.TraceEventFile; if (traceEventFile.Length == 0) { var logFile = Configuration.LogFile.Length != 0 ? Configuration.LogFile : "Cache/Intermediate/Log.txt"; traceEventFile = Path.ChangeExtension(logFile, ".trace.json"); } var path = Path.GetDirectoryName(traceEventFile); if (!string.IsNullOrEmpty(path) && !Directory.Exists(path)) Directory.CreateDirectory(path); Log.Info("Saving trace events to " + traceEventFile); var contents = new StringBuilder(); contents.Append("{\"traceEvents\": ["); var startTime = _events.Count != 0 ? _events[0].StartTime : DateTime.MinValue; for (int i = 0; i < _events.Count; i++) { var e = _events[i]; contents.Append($"{{ \"pid\":{e.ThreadId}, \"tid\":1, \"ts\":{(int)((e.StartTime - startTime).TotalMilliseconds * 1000.0)}, \"dur\":{(int)(e.Duration.TotalMilliseconds * 1000.0)}, \"ph\":\"X\", \"name\":\"{e.Name}\", \"args\":{{ \"startTime\":\"{e.StartTime.ToShortTimeString()}\" }} }}\n"); if (i + 1 != _events.Count) contents.Append(","); } contents.Append("]}"); File.WriteAllText(traceEventFile, contents.ToString()); } } }