public virtual void Play()
{
Stopwatch sw = null;
if (BenchmarkManager.Enable)
{
sw = Stopwatch.StartNew();
}
Environment.ResetMoveZone();
SpellSelector.AnalysePossibilities();
if (!Fighter.Fight.AIDebugMode)
{
ExecuteSpellCast();
ExecutePostMove();
}
if (sw != null)
{
sw.Stop();
if (sw.ElapsedMilliseconds > 50)
{
BenchmarkManager.Instance.Add(BenchmarkEntry.Create("[AI] " + Fighter, sw.Elapsed, "type", "ai",
"spells", SpellSelector.Possibilities.Select(x => x.Spell.ToString()).ToCSV(",")));
}
}
}
/// <summary>
/// Hit benchmarking checkpoint
/// </summary>
/// <param name="checkpointName"></param>
/// <param name="epicId"></param>
/// <param name="processName"></param>
/// <param name="callerProcessName"></param>
/// <param name="description"></param>
/// <param name="payload"></param>
public void Bench(string checkpointName, Guid epicId, string processName, string callerProcessName = null, string description = null, object payload = null)
{
if (!Configuration.IsEnabled)
{
return;
}
var entry = new BenchmarkEntry();
entry.Checkpoint = checkpointName;
entry.EpicId = epicId;
entry.ProcessName = processName;
entry.CallerProcessName = callerProcessName;
entry.Description = description;
entry.Payload = payload;
entry.CreatedOn = DateTime.UtcNow;
var bag = InMemoryEntiryCache.GetOrAdd(epicId, new ConcurrentBag <BenchmarkEntry>());
bag.Add(entry);
}
public override void Execute()
{
try
{
Stopwatch stopwatch = Stopwatch.StartNew();
base.Execute();
base.Parameter2.LastMessage = base.Parameter3;
stopwatch.Stop();
if (BenchmarkManager.Enable)
{
Singleton <BenchmarkManager> .Instance.RegisterEntry(BenchmarkEntry.Create(stopwatch.Elapsed, base.Parameter3));
}
}
catch (Exception ex)
{
HandledMessage <T> .logger.Error <Stump.DofusProtocol.Messages.Message, T, Exception>("[Handler : {0}] Force disconnection of client {1} : {2}", base.Parameter3, base.Parameter2, ex);
T parameter = base.Parameter2;
parameter.Disconnect();
Singleton <ExceptionManager> .Instance.RegisterException(ex);
}
}
/// <summary>
/// Get epic report data
/// </summary>
/// <param name="epicName"></param>
/// <param name="afterDate"></param>
/// <returns></returns>
public EpicsReport GetEpicReport(string epicName, DateTime afterDate)
{
if (!Configuration.IsEnabled)
{
return(new EpicsReport());
}
using (var connection = new SqlConnection(Configuration.ConnectionString))
{
var sql = $@"SELECT [Id],
[CreatedOn],
[EpicId],
[ProcessName],
[CallerProcessName],
[Checkpoint],
[Description],
[Payload]
FROM [{Configuration.TableName}]
WHERE [EpicName] = @EpicName AND [CreatedOn] >= @AfterDate";
connection.Open();
var command = new SqlCommand(sql, connection);
command.Parameters.AddWithValue("EpicName", epicName);
command.Parameters.AddWithValue("AfterDate", afterDate.ToString("yyyy-MM-dd HH:mm:ss.fffffff"));
var result = new List <BenchmarkEntry>();
using (var reader = command.ExecuteReader())
{
while (reader.Read())
{
var callerProcessName = reader.GetSqlString(4);
var description = reader.GetSqlString(6);
var payload = reader.GetSqlString(7);
var entry = new BenchmarkEntry
{
Id = reader.GetInt32(0),
CreatedOn = reader.GetDateTime(1),
EpicId = Guid.Parse(reader.GetString(2)),
ProcessName = reader.GetString(3),
CallerProcessName = callerProcessName.IsNull ? null : callerProcessName.Value,
Checkpoint = reader.GetString(5),
Description = description.IsNull ? null : description.Value,
Payload = payload.IsNull ? null : JsonConvert.DeserializeObject(payload.Value)
};
result.Add(entry);
}
}
var reports = result.GroupBy(x => x.EpicId).Select(x =>
{
var report = new EpicReport(x.Key);
report.BenchmarkEntries.AddRange(x.ToList());
return(report);
}).ToList();
var epicReport = new EpicsReport();
epicReport.EpicReports.AddRange(reports);
return(epicReport);
}
}
private void UpdateCallback(object state)
{
if ((IsDisposed || !IsRunning) ||
(Interlocked.CompareExchange(ref m_currentThreadId, Thread.CurrentThread.ManagedThreadId, 0) != 0))
{
logger.Info($"Area {this} exit callback since it's disposed");
return;
}
var updateStart = DateTime.Now;
var updateDelta = (int)((updateStart - m_lastUpdateTime).TotalMilliseconds);
long messageProcessTime = 0;
long timerProcessingTime = 0;
var timerProcessed = 0;
var processedMessages = new List <BenchmarkEntry>();
try
{
var sw = Stopwatch.StartNew();
IMessage msg;
while (m_messageQueue.TryDequeue(out msg))
{
var swMsg = Stopwatch.StartNew();
try
{
msg.Execute();
swMsg.Stop();
if (BenchmarkManager.Enable && swMsg.Elapsed.TotalMilliseconds > 50)
{
processedMessages.Add(BenchmarkEntry.Create(msg.ToString(), swMsg.Elapsed, "area", Id));
}
}
catch (Exception ex)
{
swMsg.Stop();
logger.Error("Exception raised when processing Message in {0} : {1}.", this, ex);
if (BenchmarkManager.Enable)
{
processedMessages.Add(BenchmarkEntry.Create(msg.ToString(), swMsg.Elapsed, "area", Id, "exception", ex));
}
}
}
sw.Stop();
messageProcessTime = sw.ElapsedMilliseconds;
m_isUpdating = true;
foreach (var timer in m_pausedTimers.Where(timer => timer.Enabled))
{
m_timers.Push(timer);
}
sw = Stopwatch.StartNew();
TimedTimerEntry peek;
while ((peek = m_timers.Peek()) != null && peek.NextTick <= DateTime.Now)
{
var timer = m_timers.Pop();
if (!timer.Enabled)
{
if (!timer.IsDisposed)
{
m_pausedTimers.Add(timer);
}
}
else
{
try
{
var swMsg = Stopwatch.StartNew();
timer.Trigger();
swMsg.Stop();
if (BenchmarkManager.Enable && swMsg.Elapsed.TotalMilliseconds > 20)
{
processedMessages.Add(BenchmarkEntry.Create(timer.ToString(), swMsg.Elapsed, "area", Id));
}
if (timer.Enabled)
{
m_timers.Push(timer);
}
timerProcessed++;
}
catch (Exception ex)
{
logger.Error("Exception raised when processing TimerEntry in {0} : {1}.", this, ex);
}
}
}
sw.Stop();
timerProcessingTime = sw.ElapsedMilliseconds;
}
finally
{
try
{
// we updated the map, so set our last update time to now
m_lastUpdateTime = updateStart;
TickCount++;
m_isUpdating = false;
// get the time, now that we've finished our update callback
var updateEnd = DateTime.Now;
var newUpdateDelta = updateEnd - updateStart;
// weigh old update-time 9 times and new update-time once
AverageUpdateTime = ((AverageUpdateTime * 9) + (float)(newUpdateDelta).TotalMilliseconds) / 10;
// make sure to unset the ID *before* enqueuing the task in the ThreadPool again
Interlocked.Exchange(ref m_currentThreadId, 0);
var callbackTimeout = (int)(m_updateDelay - newUpdateDelta.TotalMilliseconds);
if (callbackTimeout < 0)
{
// even if we are in a hurry: For the sake of load-balance we have to give control back to the ThreadPool
callbackTimeout = 0;
logger.Debug("Area '{0}' update lagged ({1}ms) (msg:{2}ms, timers:{3}ms, timerProc:{4}/{5})",
this, (int)newUpdateDelta.TotalMilliseconds, messageProcessTime, timerProcessingTime, timerProcessed, m_timers.Count);
foreach (var msg in processedMessages.OrderByDescending(x => x.Timestamp).Take(15))
{
logger.Debug(msg);
}
BenchmarkManager.Instance.AddRange(processedMessages.OrderByDescending(x => x.Timestamp).Take(15));
}
if (!m_running)
{
m_stoppedAsync.Set();
}
else
{
m_currentTask = Task.Factory.StartNewDelayed(callbackTimeout, UpdateCallback, this);
}
}
catch (Exception ex)
{
logger.Error("Area {0}. Could not recall callback !! Exception {1}", this, ex);
}
}
}
