Ryujinx/Ryujinx.Profiler/InternalProfile.cs

221 lines
6.9 KiB
C#
Raw Normal View History

Built in profiling (#567) * Profiler initial setup * Capture actual timing data * Profiling data dumped to file on close * Support for multiple sessions under the same name * Service profiling * Sort output for easier read * csv output * Split session into 2 seperate values * Refactor name to category * Basic profiling window dummy. Toggle with F1 or set key with config No actual data displayed yet, just a pretty triangle * Simple font rendering * Display some actual timing data * Fix font bearing being ignored * x bearing and advance. Fixed y bearing calc * Different coloured lines to make reading easier * Scrolling * Multiple columns for name * Column titles * display in ms rather than ticks * Bars to display times * Sortable columns * Regex filtering * Better instant timing calculation Fixed minor regex bug * Better filtering Better max value calculation Skip some rendering to reduce profiler weight * Variable update rate * Show/hide inactive button Some other touchups * Add missing project reference * Hide inactive and pause * Fix viewport errors * Update initial window position * Variable name cleanup * Disable timing dump by default * Internal Profile refactor and cleanup * Timing info cleanup * Profile config cleanup * Settings cleanup * Button refactor * Profile refactor * Profile window cleanup * Window manager refactor * Font service cleanup * Fixed bug in profiling method where method was called twice without profiling enabled * Allow update rates of less than 1hz * Stop using window.run because it's apparently not great for performance. Some other performance things, should only draw a new frame when something has changed * Improved time tracking to keep history * Profile window was getting too long so I added regions and split bar rendering out into partial class * Dummy graph view with button to toggle * Realtime graphing initial commit * Display totals on new bar * Simple zooming support with arrow keys * Limit graph zoom and label start and stop * Added support for timing flags * Stop data running away when paused and frame updated * Manual step button * Update at when flag issued (ie every frame) * Removed useless finish profiling call * Enable and disable profiling at compile time. * Better plage for frame swap flag, also kept enough flags to cover larger time spans * No more stopwatches created, uses PerformanceCounter now * public and internal fields to props * Move visible update to update rather than draw as it causes a lockup if called from draw Also added profile window disposal so closing main window closes profiler too * Fixed optimization settings for profiled builds * Appveyer script guess to add profiling builds * Quotes * 1 less quote * Maybe escape space? * Specify config * Different approach * Fix file paths * Fix another path * Better artifact naming * Missing - * test string * Removed for, to test * readd for * moved dashes around so artifacts can begin with letters * quote env vars * martix * Removed configs * Much more efficient capture, ConcurrentDictionary was causing too much overhead * Skip repeating pixels during draw * Stop ram usage getting too high. Compensating for cleanup doing more now * Profile CPU, execute skipped because it's just too much work * Fixed bug with skipping draws. Furthest needed to be reset every loop * Less distracting colour for timing flags * Removed profile method function. It just doesn't play nice with conditional compilation so best to remove it now before it's used a lot * Null check for category, group and item * Forgot to reset instant count/time * Increment line when blank * Fix threading conflict Fixed instant count and time. Now accuratly represents the total time and count in the buffer * Fixed bug in time rendering where times were being trimmed to an int. Also added microsecond/millisecond formatting to reduce the number of decimal places needed * Support for multiple profiling levels * Sometimes it would have to wait a long time for lock to clear so moved it to a tryenter and skip if already locked * Dumb bug regarding clearing of timestamps. Start is already removed so no need to add it to the start * Optimisations in drawing routine: Only calculate bar top and bottom once per bar rather than once per timestamp Pre-calculate the right side of the graph as it was being calculated multiple times per bar Skip rendering timestamps that occupy the same pixel space now uses the raw timestamp to decide. While technically not as accurate it's much easier as the right side of the bar doesn't have to be calculated for a skipped timestamp * Couple alignment changes * Custom equals overload for profile config. The default implpmentation was just too slow * Bump cleanup thread priority. It clears the timer queue so it need to be run frequently * Fixed bug with scrolling caused by recent rendering optimisations. Simply forgot to increment the line index on a skipped line * Stopped blocking memory disposal so much. Also parralised(?) cleanup call * Uses Arial for font. * Enable AA * Inital seperated config support * Fix profile input from keyboard * Check toggle visible key from profiler * Can't use conditional here as _profileWindow doesn't exist it non-profiling build * Removed junk from merge in sln * Fromatting cleanup for review * Fiked small bug caused by race condition * Added multiple flags with colours Added way to set max flags * Fixed flag times Dispays time flags in window * Colors for text frame times * enable and disable flags button added better fix for race crash * Re factored npad out * Explicitly specified type in foreach * Removed extra line * Added s to fix nit * Comment to clarify default time * Another s nit * Ordering nit * Uses Interlocked.Increment over lock * Unindented #if's and #regions * Comment to clarify these are indexes in the list * Uses iequatable over override equals to avoid conversion and checks at runtime * Removed no longer used variable
2019-04-26 06:53:10 +02:00
using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Linq;
using System.Threading;
using System.Threading.Tasks;
using Ryujinx.Common;
namespace Ryujinx.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);
_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 sucessfully cleared
if (queueCleared)
{
Thread.Sleep(5);
}
}
}
private bool ClearTimerQueue()
{
int count = 0;
while (_timerQueue.TryDequeue(out var item))
{
if (!Timers.TryGetValue(item.Config, out var 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 RegisterFlagReciever(Action<TimingFlag> reciever)
{
_timingFlagCallback = reciever;
}
public void Dispose()
{
_cleanupRunning = false;
_cleanupThread.Join();
}
}
}