Render Profiler in GUI (#854)

* move profiler output to gui

* addressed commits, rebased

* removed whitespaces
This commit is contained in:
emmauss 2020-02-06 11:25:47 +00:00 committed by GitHub
parent db9f8f999f
commit f2b9a9c2b0
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
41 changed files with 1358 additions and 1639 deletions

View file

@ -0,0 +1,35 @@
using Ryujinx.Common;
using System;
using System.Collections.Generic;
using System.IO;
using System.Linq;
namespace Ryujinx.Debugger.Profiler
{
public static class DumpProfile
{
public static void ToFile(string path, InternalProfile profile)
{
String fileData = "Category,Session Group,Session Item,Count,Average(ms),Total(ms)\r\n";
foreach (KeyValuePair<ProfileConfig, TimingInfo> time in profile.Timers.OrderBy(key => key.Key.Tag))
{
fileData += $"{time.Key.Category}," +
$"{time.Key.SessionGroup}," +
$"{time.Key.SessionItem}," +
$"{time.Value.Count}," +
$"{time.Value.AverageTime / PerformanceCounter.TicksPerMillisecond}," +
$"{time.Value.TotalTime / PerformanceCounter.TicksPerMillisecond}\r\n";
}
// Ensure file directory exists before write
FileInfo fileInfo = new FileInfo(path);
if (fileInfo == null)
throw new Exception("Unknown logging error, probably a bad file path");
if (fileInfo.Directory != null && !fileInfo.Directory.Exists)
Directory.CreateDirectory(fileInfo.Directory.FullName);
File.WriteAllText(fileInfo.FullName, fileData);
}
}
}

View file

@ -0,0 +1,223 @@
using Ryujinx.Common;
using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
namespace Ryujinx.Debugger.Profiler
{
public class InternalProfile
{
private struct TimerQueueValue
{
public ProfileConfig Config;
public long Time;
public bool IsBegin;
}
internal Dictionary<ProfileConfig, TimingInfo> Timers { get; set; }
private readonly object _timerQueueClearLock = new object();
private ConcurrentQueue<TimerQueueValue> _timerQueue;
private int _sessionCounter = 0;
// Cleanup thread
private readonly Thread _cleanupThread;
private bool _cleanupRunning;
private readonly long _history;
private long _preserve;
// Timing flags
private TimingFlag[] _timingFlags;
private long[] _timingFlagAverages;
private long[] _timingFlagLast;
private long[] _timingFlagLastDelta;
private int _timingFlagCount;
private int _timingFlagIndex;
private int _maxFlags;
private Action<TimingFlag> _timingFlagCallback;
public InternalProfile(long history, int maxFlags)
{
_maxFlags = maxFlags;
Timers = new Dictionary<ProfileConfig, TimingInfo>();
_timingFlags = new TimingFlag[_maxFlags];
_timingFlagAverages = new long[(int)TimingFlagType.Count];
_timingFlagLast = new long[(int)TimingFlagType.Count];
_timingFlagLastDelta = new long[(int)TimingFlagType.Count];
_timerQueue = new ConcurrentQueue<TimerQueueValue>();
_history = history;
_cleanupRunning = true;
// Create cleanup thread.
_cleanupThread = new Thread(CleanupLoop)
{
Name = "Profiler.CleanupThread"
};
_cleanupThread.Start();
}
private void CleanupLoop()
{
bool queueCleared = false;
while (_cleanupRunning)
{
// Ensure we only ever have 1 instance modifying timers or timerQueue
if (Monitor.TryEnter(_timerQueueClearLock))
{
queueCleared = ClearTimerQueue();
// Calculate before foreach to mitigate redundant calculations
long cleanupBefore = PerformanceCounter.ElapsedTicks - _history;
long preserveStart = _preserve - _history;
// Each cleanup is self contained so run in parallel for maximum efficiency
Parallel.ForEach(Timers, (t) => t.Value.Cleanup(cleanupBefore, preserveStart, _preserve));
Monitor.Exit(_timerQueueClearLock);
}
// Only sleep if queue was successfully cleared
if (queueCleared)
{
Thread.Sleep(5);
}
}
}
private bool ClearTimerQueue()
{
int count = 0;
while (_timerQueue.TryDequeue(out TimerQueueValue item))
{
if (!Timers.TryGetValue(item.Config, out TimingInfo value))
{
value = new TimingInfo();
Timers.Add(item.Config, value);
}
if (item.IsBegin)
{
value.Begin(item.Time);
}
else
{
value.End(item.Time);
}
// Don't block for too long as memory disposal is blocked while this function runs
if (count++ > 10000)
{
return false;
}
}
return true;
}
public void FlagTime(TimingFlagType flagType)
{
int flagId = (int)flagType;
_timingFlags[_timingFlagIndex] = new TimingFlag()
{
FlagType = flagType,
Timestamp = PerformanceCounter.ElapsedTicks
};
_timingFlagCount = Math.Max(_timingFlagCount + 1, _maxFlags);
// Work out average
if (_timingFlagLast[flagId] != 0)
{
_timingFlagLastDelta[flagId] = _timingFlags[_timingFlagIndex].Timestamp - _timingFlagLast[flagId];
_timingFlagAverages[flagId] = (_timingFlagAverages[flagId] == 0) ? _timingFlagLastDelta[flagId] :
(_timingFlagLastDelta[flagId] + _timingFlagAverages[flagId]) >> 1;
}
_timingFlagLast[flagId] = _timingFlags[_timingFlagIndex].Timestamp;
// Notify subscribers
_timingFlagCallback?.Invoke(_timingFlags[_timingFlagIndex]);
if (++_timingFlagIndex >= _maxFlags)
{
_timingFlagIndex = 0;
}
}
public void BeginProfile(ProfileConfig config)
{
_timerQueue.Enqueue(new TimerQueueValue()
{
Config = config,
IsBegin = true,
Time = PerformanceCounter.ElapsedTicks,
});
}
public void EndProfile(ProfileConfig config)
{
_timerQueue.Enqueue(new TimerQueueValue()
{
Config = config,
IsBegin = false,
Time = PerformanceCounter.ElapsedTicks,
});
}
public string GetSession()
{
// Can be called from multiple threads so we need to ensure no duplicate sessions are generated
return Interlocked.Increment(ref _sessionCounter).ToString();
}
public List<KeyValuePair<ProfileConfig, TimingInfo>> GetProfilingData()
{
_preserve = PerformanceCounter.ElapsedTicks;
lock (_timerQueueClearLock)
{
ClearTimerQueue();
return Timers.ToList();
}
}
public TimingFlag[] GetTimingFlags()
{
int count = Math.Max(_timingFlagCount, _maxFlags);
TimingFlag[] outFlags = new TimingFlag[count];
for (int i = 0, sourceIndex = _timingFlagIndex; i < count; i++, sourceIndex++)
{
if (sourceIndex >= _maxFlags)
sourceIndex = 0;
outFlags[i] = _timingFlags[sourceIndex];
}
return outFlags;
}
public (long[], long[]) GetTimingAveragesAndLast()
{
return (_timingFlagAverages, _timingFlagLastDelta);
}
public void RegisterFlagReceiver(Action<TimingFlag> receiver)
{
_timingFlagCallback = receiver;
}
public void Dispose()
{
_cleanupRunning = false;
_cleanupThread.Join();
}
}
}

View file

@ -0,0 +1,141 @@
using Ryujinx.Common;
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
namespace Ryujinx.Debugger.Profiler
{
public static class Profile
{
public static float UpdateRate => _settings.UpdateRate;
public static long HistoryLength => _settings.History;
private static InternalProfile _profileInstance;
private static ProfilerSettings _settings;
[Conditional("USE_DEBUGGING")]
public static void Initialize()
{
var config = ProfilerConfiguration.Load(Path.Combine(AppDomain.CurrentDomain.BaseDirectory, "ProfilerConfig.jsonc"));
_settings = new ProfilerSettings()
{
Enabled = config.Enabled,
FileDumpEnabled = config.DumpPath != "",
DumpLocation = config.DumpPath,
UpdateRate = (config.UpdateRate <= 0) ? -1 : 1.0f / config.UpdateRate,
History = (long)(config.History * PerformanceCounter.TicksPerSecond),
MaxLevel = config.MaxLevel,
MaxFlags = config.MaxFlags,
};
}
public static bool ProfilingEnabled()
{
#if USE_DEBUGGING
if (!_settings.Enabled)
return false;
if (_profileInstance == null)
_profileInstance = new InternalProfile(_settings.History, _settings.MaxFlags);
return true;
#else
return false;
#endif
}
[Conditional("USE_DEBUGGING")]
public static void FinishProfiling()
{
if (!ProfilingEnabled())
return;
if (_settings.FileDumpEnabled)
DumpProfile.ToFile(_settings.DumpLocation, _profileInstance);
_profileInstance.Dispose();
}
[Conditional("USE_DEBUGGING")]
public static void FlagTime(TimingFlagType flagType)
{
if (!ProfilingEnabled())
return;
_profileInstance.FlagTime(flagType);
}
[Conditional("USE_DEBUGGING")]
public static void RegisterFlagReceiver(Action<TimingFlag> receiver)
{
if (!ProfilingEnabled())
return;
_profileInstance.RegisterFlagReceiver(receiver);
}
[Conditional("USE_DEBUGGING")]
public static void Begin(ProfileConfig config)
{
if (!ProfilingEnabled())
return;
if (config.Level > _settings.MaxLevel)
return;
_profileInstance.BeginProfile(config);
}
[Conditional("USE_DEBUGGING")]
public static void End(ProfileConfig config)
{
if (!ProfilingEnabled())
return;
if (config.Level > _settings.MaxLevel)
return;
_profileInstance.EndProfile(config);
}
public static string GetSession()
{
#if USE_DEBUGGING
if (!ProfilingEnabled())
return null;
return _profileInstance.GetSession();
#else
return "";
#endif
}
public static List<KeyValuePair<ProfileConfig, TimingInfo>> GetProfilingData()
{
#if USE_DEBUGGING
if (!ProfilingEnabled())
return new List<KeyValuePair<ProfileConfig, TimingInfo>>();
return _profileInstance.GetProfilingData();
#else
return new List<KeyValuePair<ProfileConfig, TimingInfo>>();
#endif
}
public static TimingFlag[] GetTimingFlags()
{
#if USE_DEBUGGING
if (!ProfilingEnabled())
return new TimingFlag[0];
return _profileInstance.GetTimingFlags();
#else
return new TimingFlag[0];
#endif
}
public static (long[], long[]) GetTimingAveragesAndLast()
{
#if USE_DEBUGGING
if (!ProfilingEnabled())
return (new long[0], new long[0]);
return _profileInstance.GetTimingAveragesAndLast();
#else
return (new long[0], new long[0]);
#endif
}
}
}

View file

@ -0,0 +1,254 @@
using System;
namespace Ryujinx.Debugger.Profiler
{
public struct ProfileConfig : IEquatable<ProfileConfig>
{
public string Category;
public string SessionGroup;
public string SessionItem;
public int Level;
// Private cached variables
private string _cachedTag;
private string _cachedSession;
private string _cachedSearch;
// Public helpers to get config in more user friendly format,
// Cached because they never change and are called often
public string Search
{
get
{
if (_cachedSearch == null)
{
_cachedSearch = $"{Category}.{SessionGroup}.{SessionItem}";
}
return _cachedSearch;
}
}
public string Tag
{
get
{
if (_cachedTag == null)
_cachedTag = $"{Category}{(Session == "" ? "" : $" ({Session})")}";
return _cachedTag;
}
}
public string Session
{
get
{
if (_cachedSession == null)
{
if (SessionGroup != null && SessionItem != null)
{
_cachedSession = $"{SessionGroup}: {SessionItem}";
}
else if (SessionGroup != null)
{
_cachedSession = $"{SessionGroup}";
}
else if (SessionItem != null)
{
_cachedSession = $"---: {SessionItem}";
}
else
{
_cachedSession = "";
}
}
return _cachedSession;
}
}
/// <summary>
/// The default comparison is far too slow for the number of comparisons needed because it doesn't know what's important to compare
/// </summary>
/// <param name="obj">Object to compare to</param>
/// <returns></returns>
public bool Equals(ProfileConfig cmpObj)
{
// Order here is important.
// Multiple entries with the same item is considerable less likely that multiple items with the same group.
// Likewise for group and category.
return (cmpObj.SessionItem == SessionItem &&
cmpObj.SessionGroup == SessionGroup &&
cmpObj.Category == Category);
}
}
/// <summary>
/// Predefined configs to make profiling easier,
/// nested so you can reference as Profiles.Category.Group.Item where item and group may be optional
/// </summary>
public static class Profiles
{
public static class CPU
{
public static ProfileConfig TranslateTier0 = new ProfileConfig()
{
Category = "CPU",
SessionGroup = "TranslateTier0"
};
public static ProfileConfig TranslateTier1 = new ProfileConfig()
{
Category = "CPU",
SessionGroup = "TranslateTier1"
};
}
public static class Input
{
public static ProfileConfig ControllerInput = new ProfileConfig
{
Category = "Input",
SessionGroup = "ControllerInput"
};
public static ProfileConfig TouchInput = new ProfileConfig
{
Category = "Input",
SessionGroup = "TouchInput"
};
}
public static class GPU
{
public static class Engine2d
{
public static ProfileConfig TextureCopy = new ProfileConfig()
{
Category = "GPU.Engine2D",
SessionGroup = "TextureCopy"
};
}
public static class Engine3d
{
public static ProfileConfig CallMethod = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "CallMethod",
};
public static ProfileConfig VertexEnd = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "VertexEnd"
};
public static ProfileConfig ClearBuffers = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "ClearBuffers"
};
public static ProfileConfig SetFrameBuffer = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "SetFrameBuffer",
};
public static ProfileConfig SetZeta = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "SetZeta"
};
public static ProfileConfig UploadShaders = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "UploadShaders"
};
public static ProfileConfig UploadTextures = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "UploadTextures"
};
public static ProfileConfig UploadTexture = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "UploadTexture"
};
public static ProfileConfig UploadConstBuffers = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "UploadConstBuffers"
};
public static ProfileConfig UploadVertexArrays = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "UploadVertexArrays"
};
public static ProfileConfig ConfigureState = new ProfileConfig()
{
Category = "GPU.Engine3D",
SessionGroup = "ConfigureState"
};
}
public static class EngineM2mf
{
public static ProfileConfig CallMethod = new ProfileConfig()
{
Category = "GPU.EngineM2mf",
SessionGroup = "CallMethod",
};
public static ProfileConfig Execute = new ProfileConfig()
{
Category = "GPU.EngineM2mf",
SessionGroup = "Execute",
};
}
public static class EngineP2mf
{
public static ProfileConfig CallMethod = new ProfileConfig()
{
Category = "GPU.EngineP2mf",
SessionGroup = "CallMethod",
};
public static ProfileConfig Execute = new ProfileConfig()
{
Category = "GPU.EngineP2mf",
SessionGroup = "Execute",
};
public static ProfileConfig PushData = new ProfileConfig()
{
Category = "GPU.EngineP2mf",
SessionGroup = "PushData",
};
}
public static class Shader
{
public static ProfileConfig Decompile = new ProfileConfig()
{
Category = "GPU.Shader",
SessionGroup = "Decompile",
};
}
}
public static ProfileConfig ServiceCall = new ProfileConfig()
{
Category = "ServiceCall",
};
}
}

View file

@ -0,0 +1,32 @@
using System;
using System.Collections.Generic;
namespace Ryujinx.Debugger.Profiler
{
public static class ProfileSorters
{
public class InstantAscending : IComparer<KeyValuePair<ProfileConfig, TimingInfo>>
{
public int Compare(KeyValuePair<ProfileConfig, TimingInfo> pair1, KeyValuePair<ProfileConfig, TimingInfo> pair2)
=> pair2.Value.Instant.CompareTo(pair1.Value.Instant);
}
public class AverageAscending : IComparer<KeyValuePair<ProfileConfig, TimingInfo>>
{
public int Compare(KeyValuePair<ProfileConfig, TimingInfo> pair1, KeyValuePair<ProfileConfig, TimingInfo> pair2)
=> pair2.Value.AverageTime.CompareTo(pair1.Value.AverageTime);
}
public class TotalAscending : IComparer<KeyValuePair<ProfileConfig, TimingInfo>>
{
public int Compare(KeyValuePair<ProfileConfig, TimingInfo> pair1, KeyValuePair<ProfileConfig, TimingInfo> pair2)
=> pair2.Value.TotalTime.CompareTo(pair1.Value.TotalTime);
}
public class TagAscending : IComparer<KeyValuePair<ProfileConfig, TimingInfo>>
{
public int Compare(KeyValuePair<ProfileConfig, TimingInfo> pair1, KeyValuePair<ProfileConfig, TimingInfo> pair2)
=> StringComparer.CurrentCulture.Compare(pair1.Key.Search, pair2.Key.Search);
}
}
}

View file

@ -0,0 +1,68 @@
using Gdk;
using System;
using System.IO;
using Utf8Json;
using Utf8Json.Resolvers;
namespace Ryujinx.Debugger.Profiler
{
public class ProfilerConfiguration
{
public bool Enabled { get; private set; }
public string DumpPath { get; private set; }
public float UpdateRate { get; private set; }
public int MaxLevel { get; private set; }
public int MaxFlags { get; private set; }
public float History { get; private set; }
/// <summary>
/// Loads a configuration file from disk
/// </summary>
/// <param name="path">The path to the JSON configuration file</param>
public static ProfilerConfiguration Load(string path)
{
var resolver = CompositeResolver.Create(
new[] { new ConfigurationEnumFormatter<Key>() },
new[] { StandardResolver.AllowPrivateSnakeCase }
);
if (!File.Exists(path))
{
throw new FileNotFoundException($"Profiler configuration file {path} not found");
}
using (Stream stream = File.OpenRead(path))
{
return JsonSerializer.Deserialize<ProfilerConfiguration>(stream, resolver);
}
}
private class ConfigurationEnumFormatter<T> : IJsonFormatter<T>
where T : struct
{
public void Serialize(ref JsonWriter writer, T value, IJsonFormatterResolver formatterResolver)
{
formatterResolver.GetFormatterWithVerify<string>()
.Serialize(ref writer, value.ToString(), formatterResolver);
}
public T Deserialize(ref JsonReader reader, IJsonFormatterResolver formatterResolver)
{
if (reader.ReadIsNull())
{
return default(T);
}
string enumName = formatterResolver.GetFormatterWithVerify<string>()
.Deserialize(ref reader, formatterResolver);
if (Enum.TryParse<T>(enumName, out T result))
{
return result;
}
return default(T);
}
}
}
}

View file

@ -0,0 +1,17 @@
namespace Ryujinx.Debugger.Profiler
{
public class ProfilerSettings
{
// Default settings for profiler
public bool Enabled { get; set; } = false;
public bool FileDumpEnabled { get; set; } = false;
public string DumpLocation { get; set; } = "";
public float UpdateRate { get; set; } = 0.1f;
public int MaxLevel { get; set; } = 0;
public int MaxFlags { get; set; } = 1000;
// 19531225 = 5 seconds in ticks on most pc's.
// It should get set on boot to the time specified in config
public long History { get; set; } = 19531225;
}
}

View file

@ -0,0 +1,17 @@
namespace Ryujinx.Debugger.Profiler
{
public enum TimingFlagType
{
FrameSwap = 0,
SystemFrame = 1,
// Update this for new flags
Count = 2,
}
public struct TimingFlag
{
public TimingFlagType FlagType;
public long Timestamp;
}
}

View file

@ -0,0 +1,174 @@
using System;
using System.Collections.Generic;
namespace Ryujinx.Debugger.Profiler
{
public struct Timestamp
{
public long BeginTime;
public long EndTime;
}
public class TimingInfo
{
// Timestamps
public long TotalTime { get; set; }
public long Instant { get; set; }
// Measurement counts
public int Count { get; set; }
public int InstantCount { get; set; }
// Work out average
public long AverageTime => (Count == 0) ? -1 : TotalTime / Count;
// Intentionally not locked as it's only a get count
public bool IsActive => _timestamps.Count > 0;
public long BeginTime
{
get
{
lock (_timestampLock)
{
if (_depth > 0)
{
return _currentTimestamp.BeginTime;
}
return -1;
}
}
}
// Timestamp collection
private List<Timestamp> _timestamps;
private readonly object _timestampLock = new object();
private readonly object _timestampListLock = new object();
private Timestamp _currentTimestamp;
// Depth of current timer,
// each begin call increments and each end call decrements
private int _depth;
public TimingInfo()
{
_timestamps = new List<Timestamp>();
_depth = 0;
}
public void Begin(long beginTime)
{
lock (_timestampLock)
{
// Finish current timestamp if already running
if (_depth > 0)
{
EndUnsafe(beginTime);
}
BeginUnsafe(beginTime);
_depth++;
}
}
private void BeginUnsafe(long beginTime)
{
_currentTimestamp.BeginTime = beginTime;
_currentTimestamp.EndTime = -1;
}
public void End(long endTime)
{
lock (_timestampLock)
{
_depth--;
if (_depth < 0)
{
throw new Exception("Timing info end called without corresponding begin");
}
EndUnsafe(endTime);
// Still have others using this timing info so recreate start for them
if (_depth > 0)
{
BeginUnsafe(endTime);
}
}
}
private void EndUnsafe(long endTime)
{
_currentTimestamp.EndTime = endTime;
lock (_timestampListLock)
{
_timestamps.Add(_currentTimestamp);
}
long delta = _currentTimestamp.EndTime - _currentTimestamp.BeginTime;
TotalTime += delta;
Instant += delta;
Count++;
InstantCount++;
}
// Remove any timestamps before given timestamp to free memory
public void Cleanup(long before, long preserveStart, long preserveEnd)
{
lock (_timestampListLock)
{
int toRemove = 0;
int toPreserveStart = 0;
int toPreserveLen = 0;
for (int i = 0; i < _timestamps.Count; i++)
{
if (_timestamps[i].EndTime < preserveStart)
{
toPreserveStart++;
InstantCount--;
Instant -= _timestamps[i].EndTime - _timestamps[i].BeginTime;
}
else if (_timestamps[i].EndTime < preserveEnd)
{
toPreserveLen++;
}
else if (_timestamps[i].EndTime < before)
{
toRemove++;
InstantCount--;
Instant -= _timestamps[i].EndTime - _timestamps[i].BeginTime;
}
else
{
// Assume timestamps are in chronological order so no more need to be removed
break;
}
}
if (toPreserveStart > 0)
{
_timestamps.RemoveRange(0, toPreserveStart);
}
if (toRemove > 0)
{
_timestamps.RemoveRange(toPreserveLen, toRemove);
}
}
}
public Timestamp[] GetAllTimestamps()
{
lock (_timestampListLock)
{
Timestamp[] returnTimestamps = new Timestamp[_timestamps.Count];
_timestamps.CopyTo(returnTimestamps);
return returnTimestamps;
}
}
}
}