Profiler

From Unify Community Wiki
(Difference between revisions)
Jump to: navigation, search
(C# - Profiler.cs for the iPhone: modified to use DateTime.UtcNow instead of DateTime.Now)
m (C# - Profiler.cs for the iPhone: fixed the formatting)
Line 168: Line 168:
 
using System;
 
using System;
 
using UnityEngine;
 
using UnityEngine;
+
 
 
public class Profiler
 
public class Profiler
 
{
 
{
    public struct ProfilePoint
+
public struct ProfilePoint
    {
+
{
        public DateTime lastRecorded;
+
public DateTime lastRecorded;
        public TimeSpan totalTime;
+
public TimeSpan totalTime;
        public int totalCalls;
+
public int totalCalls;
    }
+
}
 
+
 
    private static Hashtable profiles = new Hashtable();
+
private static Hashtable profiles = new Hashtable();
    private static DateTime startTime = DateTime.UtcNow;
+
private static DateTime startTime = DateTime.UtcNow;
 
+
 
    private Profiler()
+
private Profiler()
    {
+
{
    }
+
}
 
+
 
    public static void StartProfile(string tag)
+
public static void StartProfile(string tag)
    {
+
{
        ProfilePoint point;
+
ProfilePoint point;
     
+
 
                if (profiles.ContainsKey(tag))
+
if (profiles.ContainsKey(tag))
                point = (ProfilePoint)profiles[tag];
+
point = (ProfilePoint)profiles[tag];
                else point = new ProfilePoint();
+
else point = new ProfilePoint();
        point.lastRecorded = DateTime.UtcNow;
+
point.lastRecorded = DateTime.UtcNow;
        profiles[tag] = point;
+
profiles[tag] = point;
    }
+
}
 
+
 
    public static void EndProfile(string tag)
+
public static void EndProfile(string tag)
    {
+
{
        if (!profiles.ContainsKey(tag))
+
if (!profiles.ContainsKey(tag))
        {
+
{
            Debug.LogError("Can only end profiling for a tag which has already been started (tag was " + tag + ")");
+
Debug.LogError("Can only end profiling for a tag which has already been started (tag was " + tag + ")");
            return;
+
return;
        }
+
}
        ProfilePoint point = (ProfilePoint)profiles[tag];
+
ProfilePoint point = (ProfilePoint)profiles[tag];
        point.totalTime += DateTime.UtcNow - point.lastRecorded;
+
point.totalTime += DateTime.UtcNow - point.lastRecorded;
        ++point.totalCalls;
+
++point.totalCalls;
        profiles[tag] = point;
+
profiles[tag] = point;
    }
+
}
 
+
 
    public static void Reset()
+
public static void Reset()
    {
+
{
        profiles.Clear();
+
profiles.Clear();
        startTime = DateTime.UtcNow;
+
startTime = DateTime.UtcNow;
    }
+
}
 
+
 
    public static void PrintResults()
+
public static void PrintResults()
    {
+
{
        TimeSpan endTime = DateTime.UtcNow - startTime;
+
TimeSpan endTime = DateTime.UtcNow - startTime;
        System.Text.StringBuilder output = new System.Text.StringBuilder();
+
System.Text.StringBuilder output = new System.Text.StringBuilder();
        output.Append("============================\n\t\t\t\tProfile results:\n============================\n");
+
output.Append("============================\n\t\t\t\tProfile results:\n============================\n");
        foreach(DictionaryEntry pair in profiles)
+
foreach(DictionaryEntry pair in profiles)
        {
+
{
            double totalTime = ((ProfilePoint)pair.Value).totalTime.TotalSeconds;
+
double totalTime = ((ProfilePoint)pair.Value).totalTime.TotalSeconds;
            int totalCalls = ((ProfilePoint)pair.Value).totalCalls;
+
int totalCalls = ((ProfilePoint)pair.Value).totalCalls;
            if (totalCalls < 1) continue;
+
if (totalCalls < 1) continue;
            output.Append("\nProfile ");
+
output.Append("\nProfile ");
            output.Append((string)pair.Key);
+
output.Append((string)pair.Key);
            output.Append(" took ");
+
output.Append(" took ");
            output.Append(totalTime.ToString("F5"));
+
output.Append(totalTime.ToString("F5"));
            output.Append(" seconds to complete over ");
+
output.Append(" seconds to complete over ");
            output.Append(totalCalls);
+
output.Append(totalCalls);
            output.Append(" iteration");
+
output.Append(" iteration");
            if (totalCalls != 1) output.Append("s");
+
if (totalCalls != 1) output.Append("s");
            output.Append(", averaging ");
+
output.Append(", averaging ");
            output.Append((totalTime / totalCalls).ToString("F5"));
+
output.Append((totalTime / totalCalls).ToString("F5"));
            output.Append(" seconds per call");
+
output.Append(" seconds per call");
        }
+
}
        output.Append("\n\n============================\n\t\tTotal runtime: ");
+
output.Append("\n\n============================\n\t\tTotal runtime: ");
        output.Append(endTime.TotalSeconds.ToString("F3"));
+
output.Append(endTime.TotalSeconds.ToString("F3"));
        output.Append(" seconds\n============================");
+
output.Append(" seconds\n============================");
        Debug.Log(output.ToString());
+
Debug.Log(output.ToString());
    }
+
}
 
}</csharp>
 
}</csharp>

Revision as of 02:29, 25 August 2009

Author: Michael Garforth


Contents

Overview

This C# class gives simple access to simple profiling of code

The script can be placed in an early compilation pass (e.g. Plugins directory) so that it can be used from any language

It has no dependencies besides .NET and Unity


Use

Profiler.StartProfile(tag) - Use this to start the profile timer for the specified tag

Profiler.EndProfile(tag) - Use this to end the profile of the specified tag

Profiler.Reset() - Remove all profile data and reset the timer, generally not needed

Profiler.PrintResults() - Output all profile data to the console, usually called in OnApplicationQuit() from one location


Note: Match up every start tag with an end tag, otherwise the timing data will be wrong

Note: The profiler can work across scripts and across scenes by starting the tag in one, and ending it in another. (E.G.: Use: Profiler.StartProfile("LoadLevel"); just before Application.LoadLevel(1); and Profiler.EndProfile("LoadLevel"); on a script's function Awake(); in the new scene.)

Example - TestProfile.cs

<csharp>using UnityEngine;

public class TestProfile : MonoBehaviour { private float outputTest = 0;

void Start() { Profiler.StartProfile("Start"); }

void Update () { Profiler.StartProfile("Update"); for (int i = 0; i < 100; ++i) outputTest += Mathf.Sin(i * Time.time); Profiler.EndProfile("Update"); }

void OnApplicationQuit() { Profiler.EndProfile("Start"); Debug.Log("outputTest is " + outputTest.ToString("F3")); Profiler.PrintResults(); } }</csharp>


Output:

============================

Profile results:

============================


Profile Update took 0.03267 seconds to complete over 1568 iterations, averaging 0.00002 seconds per call

Profile Start took 7.56886 seconds to complete over 1 iteration, averaging 7.56886 seconds per call


============================

Total runtime: 7.580 seconds

============================


C# - Profiler.cs

The script should be named Profiler.cs


<csharp>using System.Collections.Generic; using System; using UnityEngine;

public class Profiler { public struct ProfilePoint { public DateTime lastRecorded; public TimeSpan totalTime; public int totalCalls; }

private static Dictionary<string, ProfilePoint> profiles = new Dictionary<string, ProfilePoint>(); private static DateTime startTime = DateTime.UtcNow;

private Profiler() { }

public static void StartProfile(string tag) { ProfilePoint point;

profiles.TryGetValue(tag, out point); point.lastRecorded = DateTime.UtcNow; profiles[tag] = point; }

public static void EndProfile(string tag) { if (!profiles.ContainsKey(tag)) { Debug.LogError("Can only end profiling for a tag which has already been started (tag was " + tag + ")"); return; } ProfilePoint point = profiles[tag]; point.totalTime += DateTime.UtcNow - point.lastRecorded; ++point.totalCalls; profiles[tag] = point; }

public static void Reset() { profiles.Clear(); startTime = DateTime.UtcNow; }

public static void PrintResults() { TimeSpan endTime = DateTime.UtcNow - startTime; System.Text.StringBuilder output = new System.Text.StringBuilder(); output.Append("============================\n\t\t\t\tProfile results:\n============================\n"); foreach(KeyValuePair<string, ProfilePoint> pair in profiles) { double totalTime = pair.Value.totalTime.TotalSeconds; int totalCalls = pair.Value.totalCalls; if (totalCalls < 1) continue; output.Append("\nProfile "); output.Append(pair.Key); output.Append(" took "); output.Append(totalTime.ToString("F5")); output.Append(" seconds to complete over "); output.Append(totalCalls); output.Append(" iteration"); if (totalCalls != 1) output.Append("s"); output.Append(", averaging "); output.Append((totalTime / totalCalls).ToString("F5")); output.Append(" seconds per call"); } output.Append("\n\n============================\n\t\tTotal runtime: "); output.Append(endTime.TotalSeconds.ToString("F3")); output.Append(" seconds\n============================"); Debug.Log(output.ToString()); } }</csharp>

C# - Profiler.cs for the iPhone

The script should be named Profiler.cs (The generic key-value code was changed into non generic (dictionary to hashtable) - which means that a) need to cast when you remove from it b) need to use DictionaryEntry instead of KeyValuePair.)


<csharp>using System.Collections; using System; using UnityEngine;

public class Profiler { public struct ProfilePoint { public DateTime lastRecorded; public TimeSpan totalTime; public int totalCalls; }

private static Hashtable profiles = new Hashtable(); private static DateTime startTime = DateTime.UtcNow;

private Profiler() { }

public static void StartProfile(string tag) { ProfilePoint point;

if (profiles.ContainsKey(tag)) point = (ProfilePoint)profiles[tag]; else point = new ProfilePoint(); point.lastRecorded = DateTime.UtcNow; profiles[tag] = point; }

public static void EndProfile(string tag) { if (!profiles.ContainsKey(tag)) { Debug.LogError("Can only end profiling for a tag which has already been started (tag was " + tag + ")"); return; } ProfilePoint point = (ProfilePoint)profiles[tag]; point.totalTime += DateTime.UtcNow - point.lastRecorded; ++point.totalCalls; profiles[tag] = point; }

public static void Reset() { profiles.Clear(); startTime = DateTime.UtcNow; }

public static void PrintResults() { TimeSpan endTime = DateTime.UtcNow - startTime; System.Text.StringBuilder output = new System.Text.StringBuilder(); output.Append("============================\n\t\t\t\tProfile results:\n============================\n"); foreach(DictionaryEntry pair in profiles) { double totalTime = ((ProfilePoint)pair.Value).totalTime.TotalSeconds; int totalCalls = ((ProfilePoint)pair.Value).totalCalls; if (totalCalls < 1) continue; output.Append("\nProfile "); output.Append((string)pair.Key); output.Append(" took "); output.Append(totalTime.ToString("F5")); output.Append(" seconds to complete over "); output.Append(totalCalls); output.Append(" iteration"); if (totalCalls != 1) output.Append("s"); output.Append(", averaging "); output.Append((totalTime / totalCalls).ToString("F5")); output.Append(" seconds per call"); } output.Append("\n\n============================\n\t\tTotal runtime: "); output.Append(endTime.TotalSeconds.ToString("F3")); output.Append(" seconds\n============================"); Debug.Log(output.ToString()); } }</csharp>

Personal tools
Namespaces

Variants
Actions
Navigation
Extras
Toolbox