warrentyexpired/ModernUO
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions 1

fix: Adds more debugging to the timer system. Simplifies the timer pool. (#1195)

Browse source
This commit is contained in:
Kamron Batman 2022-10-17 23:25:49 -07:00 • committed by GitHub
parent d5416b6dec
commit 919b7e9416
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 99 additions and 38 deletions
Download patch file Download diff file Expand all files Collapse all files

12
Projects/Server/Timer/Timer.DelayCall.cs
View file

@ -144,11 +144,7 @@ public partial class Timer
internal override void OnDetach()
{
if (Running)
{
logger.Error("Timer is returned while still running!\n{StackTrace}", new StackTrace());
return;
}
base.OnDetach();
if (_returnOnDetach)
{
@ -177,10 +173,6 @@ public partial class Timer
var timer = GetFromPool();
if (timer != null)
{
#if DEBUG_TIMERS
logger.Information("Getting from pool: ({Count} / {Capacity})", _poolCount, _poolCapacity);
#endif
timer.Init(delay, interval, count);
timer._continuation = callback;
timer._returnOnDetach = false;
@ -191,8 +183,6 @@ public partial class Timer
return timer;
}
_timerPoolDepletionAmount++;
#if DEBUG_TIMERS
logger.Warning("Timer pool depleted and timer was allocated.\n{StackTrace}", new StackTrace());
#endif

26
Projects/Server/Timer/Timer.Pool.cs
View file

@ -21,33 +21,27 @@ namespace Server;
public partial class Timer
{
private const int _timerPoolDepletionThreshold = 128; // Maximum timers allocated in a single tick before we force adjust
private static int _timerPoolDepletionAmount; // Amount the pool has been depleted by
private static int _maxPoolCapacity;
private static int _poolCapacity;
private static int _poolCount;
private static DelayCallTimer _poolHead;
private static int _isRefilling;
private static bool _isRefilling;
public static void CheckTimerPool()
{
// Anything less than this threshold and we are ok with the number of allocations.
if (_timerPoolDepletionAmount < _timerPoolDepletionThreshold)
if (_poolCount > 0 || _isRefilling)
{
_timerPoolDepletionAmount = 0;
return;
}
var growthFactor = Math.DivRem(_timerPoolDepletionAmount, _poolCapacity, out var rem);
var amountToGrow = _poolCapacity * (growthFactor + (rem > 0 ? 1 : 0));
var amountToGrow = _poolCapacity * 2;
var amountToRefill = Math.Min(_maxPoolCapacity, amountToGrow);
var maximumHit = amountToGrow > amountToRefill ? " Maximum pool size has been reached." : "";
var warningMessage = $"Timer pool depleted by {{Amount}}. Refilling with {{AmountRefill}}.{maximumHit}";
var warningMessage = $"Refilling timer pool with {{AmountRefill}}.{maximumHit}";
logger.Warning(warningMessage, _timerPoolDepletionAmount, amountToRefill);
logger.Warning(warningMessage, amountToRefill);
RefillPoolAsync(amountToRefill);
_timerPoolDepletionAmount = 0;
}
public static void ConfigureTimerPool()
@ -64,9 +58,6 @@ public partial class Timer
tail.Attach(_poolHead);
_poolHead = head;
_poolCount += amount;
#if DEBUG_TIMERS
logger.Information("Returning to pool. ({Count} / {Capacity})", _poolCount, _poolCapacity);
#endif
}
private static DelayCallTimer GetFromPool()
@ -109,10 +100,7 @@ public partial class Timer
internal static async void RefillPoolAsync(int amountToRefill)
{
if (Interlocked.CompareExchange(ref _isRefilling, 0, 1) == 1)
{
return;
}
_isRefilling = true;
var (headTimer, tailTimer) = await Task.Run(
() =>
@ -125,6 +113,6 @@ public partial class Timer
ReturnToPool(amountToRefill, headTimer, tailTimer);
_poolCapacity = amountToRefill;
_isRefilling = 0;
_isRefilling = false;
}
}

2
Projects/Server/Timer/Timer.TimerWheel.cs
View file

@ -208,7 +208,7 @@ public partial class Timer
public static void DumpInfo(TextWriter tw)
{
tw.WriteLine($"Date: {Core.Now.ToLocalTime()}\n");
tw.WriteLine($"Pool - Count: {_poolCount - _timerPoolDepletionAmount}; Size {_poolCapacity}\n");
tw.WriteLine($"Pool - Count: {_poolCount}; Capacity {_poolCapacity}\n");
var total = 0.0;
var hash = new Dictionary<string, int>();

87
Projects/Server/Timer/Timer.cs
View file

@ -14,6 +14,7 @@
*************************************************************************/
using System;
using System.Diagnostics;
using Server.Diagnostics;
using Server.Logging;
@ -51,6 +52,8 @@ public partial class Timer
_nextTimer = null;
_prevTimer = null;
Next = Core.Now + Delay;
_ring = -1;
_slot = -1;
var prof = GetProfile();
@ -76,6 +79,29 @@ public partial class Timer
public Timer Start()
{
if (World.WorldState is WorldState.Initial or WorldState.Saving)
{
logger.Error(
"Attempted to start timer {Timer} ({HashCode}) while world is {State}\n{StackTrace}",
GetType(),
GetHashCode(),
World.WorldState,
new StackTrace()
);
}
#if THREADGUARD
if (Thread.CurrentThread != Core.Thread)
{
logger.Error(
"Attempted to start timer {Timer} ({HashCode}) from an invalid thread!\n{StackTrace}",
GetType(),
GetHashCode(),
new StackTrace()
);
}
#endif
if (Running)
{
return this;
@ -97,6 +123,29 @@ public partial class Timer
public void Stop()
{
if (World.WorldState is WorldState.Initial or WorldState.Saving)
{
logger.Error(
"Attempted to stop timer {Timer} ({HashCode}) while world is {State}\n{StackTrace}",
GetType(),
GetHashCode(),
World.WorldState,
new StackTrace()
);
}
#if THREADGUARD
if (Thread.CurrentThread != Core.Thread)
{
logger.Error(
"Attempted to stop timer {Timer} ({HashCode}) from an invalid thread!\n{StackTrace}",
GetType(),
GetHashCode(),
new StackTrace()
);
}
#endif
if (!Running)
{
return;
@ -132,9 +181,39 @@ public partial class Timer
private void Attach(Timer timer)
{
#if DEBUG_TIMERS
if (_prevTimer != null)
{
logger.Error(
"{Timer} ({HashCode}) attached with a previous timer already set!",
this,
GetHashCode()
);
}
if (_nextTimer != null)
{
logger.Error(
"{Timer} ({HashCode}) attached with a next timer already set!",
this,
GetHashCode()
);
}
#endif
_nextTimer = timer;
if (timer != null)
{
#if DEBUG_TIMERS
if (timer._prevTimer != null)
{
logger.Error(
"{Timer} ({HashCode}) attached from with a previous timer already set!",
timer,
timer.GetHashCode()
);
}
#endif
timer._prevTimer = this;
}
}
@ -157,5 +236,13 @@ public partial class Timer
internal virtual void OnDetach()
{
if (Running)
{
logger.Error("{Timer} detached while still running!\n{StackTrace}", this, new StackTrace());
return;
}
_ring = -1;
_slot = -1;
}
}

6
Projects/UOContent/Misc/BuffIcons.cs
View file

@ -9,8 +9,7 @@ namespace Server
{
private TimerExecutionToken _timerToken;
public BuffInfo(BuffIcon iconID, int titleCliloc)
: this(iconID, titleCliloc, titleCliloc + 1)
public BuffInfo(BuffIcon iconID, int titleCliloc) : this(iconID, titleCliloc, titleCliloc + 1)
{
}
@ -105,8 +104,6 @@ namespace Server
public long TimeStart { get; }
public TimerExecutionToken TimerToken => _timerToken;
public bool RetainThroughDeath { get; }
public TextDefinition Args { get; }
@ -139,6 +136,7 @@ namespace Server
public static void RemoveBuff(Mobile m, BuffInfo b)
{
b._timerToken.Cancel();
(m as PlayerMobile)?.RemoveBuff(b);
}

4
Projects/UOContent/Mobiles/PlayerMobile.cs
View file

@ -4589,13 +4589,11 @@ namespace Server.Mobiles
public void RemoveBuff(BuffIcon b)
{
if (m_BuffTable == null || !m_BuffTable.Remove(b, out var info))
if (m_BuffTable?.Remove(b) != true)
{
return;
}
info.TimerToken.Cancel();
if (NetState?.BuffIcon == true)
{
BuffInfo.SendRemoveBuffPacket(NetState, Serial, b);