using UnityEngine; using System.Collections.Generic; using System.Collections.ObjectModel; using System.IO; using UnityEngine.Profiling; using System.Runtime.Serialization; using System.Runtime.Serialization.Json; #if UNITY_EDITOR using UnityEditor; #endif namespace MLAgents { [DataContract] public class TimerNode { static string s_Separator = "."; static double s_TicksToSeconds = 1e-7; // 100 ns per tick /// /// Full name of the node. This is the node's parents full name concatenated with this node's name /// string m_FullName; /// /// Child nodes, indexed by name. /// [DataMember(Name="children", Order=999)] Dictionary m_Children; /// /// Custom sampler used to add timings to the profiler. /// private CustomSampler m_Sampler; /// /// Number of total ticks elapsed for this node. /// long m_TotalTicks = 0; /// /// If the node is currently running, the time (in ticks) when the node was started. /// If the node is not running, is set to 0. /// long m_TickStart = 0; /// /// Number of times the corresponding code block has been called. /// [DataMember(Name="count")] int m_NumCalls = 0; /// /// The total recorded ticks for the timer node, plus the currently elapsed ticks /// if the timer is still running (i.e. if m_TickStart is non-zero). /// public long CurrentTicks { get { long currentTicks = m_TotalTicks; if (m_TickStart != 0) { currentTicks += (System.DateTime.Now.Ticks - m_TickStart); } return currentTicks; } } /// /// Total elapsed seconds. /// [DataMember(Name="total")] public double TotalSeconds { get { return CurrentTicks * s_TicksToSeconds; } set { } // Serialization needs this, but unused. } /// /// Total seconds spent in this block, excluding it's children. /// [DataMember(Name="self")] public double SelfSeconds { get { long totalChildTicks = 0; if (m_Children != null) { foreach(var child in m_Children.Values) { totalChildTicks += child.m_TotalTicks; } } var selfTicks = Mathf.Max(0, CurrentTicks - totalChildTicks); return selfTicks * s_TicksToSeconds; } set { } // Serialization needs this, but unused. } public IReadOnlyDictionary Children { get { return m_Children; } } public int NumCalls { get { return m_NumCalls; } } public TimerNode(string name, bool isRoot=false) { m_FullName = name; if (isRoot) { // The root node is considered always running. This means that when we output stats, it'll // have a sensible value for total time (the running time since reset). // The root node doesn't have a sampler since that could interfere with the profiler. m_NumCalls = 1; m_TickStart = System.DateTime.Now.Ticks; } else { m_Sampler = CustomSampler.Create(m_FullName); } } /// /// Start timing a block of code. /// public void Begin() { m_Sampler?.Begin(); m_TickStart = System.DateTime.Now.Ticks; } /// /// Stop timing a block of code, and increment internal counts. /// public void End() { var elapsed = System.DateTime.Now.Ticks - m_TickStart; m_TotalTicks += elapsed; m_TickStart = 0; m_NumCalls++; m_Sampler?.End(); } /// /// Return a child node for the given name. /// The children dictionary will be created if it does not already exist, and /// a new Node will be created if it's not already in the dictionary. /// Note that these allocations only happen once for a given timed block. /// /// /// public TimerNode GetChild(string name) { // Lazily create the children dictionary. if (m_Children == null) { m_Children = new Dictionary(); } if (!m_Children.ContainsKey(name)) { var childFullName = m_FullName + s_Separator + name; var newChild = new TimerNode(childFullName); m_Children[name] = newChild; return newChild; } return m_Children[name]; } /// /// Recursively form a string representing the current timer information. /// /// /// /// public string DebugGetTimerString(string parentName = "", int level = 0) { string indent = new string(' ', 2 * level); // TODO generalize string shortName = (level == 0) ? m_FullName : m_FullName.Replace(parentName + s_Separator, ""); string timerString = ""; if (level == 0) { timerString = $"{shortName}(root)\n"; } else { timerString = $"{indent}{shortName}\t\traw={TotalSeconds} rawCount={m_NumCalls}\n"; } // TODO use stringbuilder? might be overkill since this is only debugging code? if (m_Children != null) { foreach (TimerNode c in m_Children.Values) { timerString += c.DebugGetTimerString(m_FullName, level + 1); } } return timerString; } } /// /// A "stack" of timers that allows for lightweight hierarchical profiling of long-running processes. /// Example usage: /// /// using(TimerStack.Instance.Scoped("foo")) /// { /// doSomeWork(); /// for (int i=0; i<5; i++) /// { /// using(myTimer.Scoped("bar")) /// { /// doSomeMoreWork(); /// } /// } /// } /// /// /// This implements the Singleton pattern (solution 4) as described in /// https://csharpindepth.com/articles/singleton /// public class TimerStack : System.IDisposable { private static readonly TimerStack instance = new TimerStack(); Stack m_Stack; TimerNode m_RootNode; // Explicit static constructor to tell C# compiler // not to mark type as beforefieldinit static TimerStack() { } private TimerStack() { Reset(); } public void Reset(string name="root") { m_Stack = new Stack(); m_RootNode = new TimerNode(name, true); m_Stack.Push(m_RootNode); } public static TimerStack Instance { get { return instance; } } public TimerNode RootNode { get { return m_RootNode; } } private void Push(string name) { TimerNode current = m_Stack.Peek(); TimerNode next = current.GetChild(name); m_Stack.Push(next); next.Begin(); } private void Pop() { var node = m_Stack.Pop(); node.End(); } /// /// Start a scoped timer. This should be used with the "using" statement. /// /// /// public TimerStack Scoped(string name) { Push(name); return this; } /// /// Closes the current scoped timer. This should never be called directly, only /// at the end of a "using" statement. /// Note that the instance is not actually disposed of; this is just to allow it to be used /// conveniently with "using". /// public void Dispose() { Pop(); } /// /// Get a string representation of the timers. /// Potentially slow so call sparingly. /// /// public string DebugGetTimerString() { return m_RootNode.DebugGetTimerString(); } /// /// Save the timers in JSON format to the provided filename. /// If the filename is null, a default one will be used. /// /// public void SaveJsonTimers(string filename=null) { if (filename == null) { var fullpath = Path.GetFullPath("."); filename = $"{fullpath}/csharp_timers.json"; } var fs = new FileStream(filename, FileMode.Create, FileAccess.Write); SaveJsonTimers(fs); fs.Close(); } /// /// Write the timers in JSON format to the provided stream. /// /// public void SaveJsonTimers(Stream stream) { var jsonSettings = new DataContractJsonSerializerSettings(); jsonSettings.UseSimpleDictionaryFormat = true; var ser = new DataContractJsonSerializer(typeof(TimerNode), jsonSettings); ser.WriteObject(stream, m_RootNode); } } }