diff --git a/Source/ACE.Common/GameConfiguration.cs b/Source/ACE.Common/GameConfiguration.cs index 686b6a1cbb..daa23d472b 100644 --- a/Source/ACE.Common/GameConfiguration.cs +++ b/Source/ACE.Common/GameConfiguration.cs @@ -15,6 +15,10 @@ public class GameConfiguration public string DatFilesDirectory { get; set; } + [System.ComponentModel.DefaultValue(false)] + [JsonProperty(DefaultValueHandling = DefaultValueHandling.Populate)] + public bool ServerPerformanceMonitorAutoStart { get; set; } + [System.ComponentModel.DefaultValue(false)] [JsonProperty(DefaultValueHandling = DefaultValueHandling.Populate)] public bool WorldDatabasePrecaching { get; set; } diff --git a/Source/ACE.Common/RateMonitor.cs b/Source/ACE.Common/RateMonitor.cs index d7e52a5bcc..268a333c93 100644 --- a/Source/ACE.Common/RateMonitor.cs +++ b/Source/ACE.Common/RateMonitor.cs @@ -30,12 +30,27 @@ public class RateMonitor /// public double AverageEventDuration => TotalSeconds / TotalEvents; + public void ResetEvent() + { + stopwatch.Reset(); + } + public void RegisterEventStart() { stopwatch.Reset(); stopwatch.Start(); } + public void PauseEvent() + { + stopwatch.Stop(); + } + + public void ResumeEvent() + { + stopwatch.Start(); + } + /// /// returns the elapsed seconds for this event /// @@ -43,7 +58,12 @@ public double RegisterEventEnd() { stopwatch.Stop(); - LastEvent = stopwatch.Elapsed.TotalSeconds; + return RegisterEvent(stopwatch.Elapsed.TotalSeconds); + } + + public double RegisterEvent(double totalSeconds) + { + LastEvent = totalSeconds; TotalEvents++; TotalSeconds += LastEvent; diff --git a/Source/ACE.Server/Command/Handlers/AdminCommands.cs b/Source/ACE.Server/Command/Handlers/AdminCommands.cs index 95a87338f3..e3bcc13cec 100644 --- a/Source/ACE.Server/Command/Handlers/AdminCommands.cs +++ b/Source/ACE.Server/Command/Handlers/AdminCommands.cs @@ -2060,8 +2060,10 @@ public static void HandleServerStatus(Session session, params string[] parameter sb.Append($"{activeLandblocks.Count:N0} active landblocks - Players: {players:N0}, Creatures: {creatures:N0}, Missiles: {missiles:N0}, Other: {other:N0}, Total: {total:N0}.{'\n'}"); // 11 total blocks loaded. 11 active. 0 pending dormancy. 0 dormant. 314 unloaded. // 11 total blocks loaded. 11 active. 0 pending dormancy. 0 dormant. 314 unloaded. - sb.Append($"UpdateGameWorld {(DateTime.UtcNow - WorldManager.UpdateGameWorld5MinLastReset).TotalMinutes:N2} min - {WorldManager.UpdateGameWorld5MinRM}.{'\n'}"); - sb.Append($"UpdateGameWorld {(DateTime.UtcNow - WorldManager.UpdateGameWorld60MinLastReset).TotalMinutes:N2} min - {WorldManager.UpdateGameWorld60MinRM}.{'\n'}"); + if (ServerPerformanceMonitor.IsRunning) + sb.Append($"Server Performance Monitor - UpdateGameWorld ~5m {ServerPerformanceMonitor.GetMonitor5m(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_Entire).AverageEventDuration:N3}, ~1h {ServerPerformanceMonitor.GetMonitor1h(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_Entire).AverageEventDuration:N3} s{'\n'}"); + else + sb.Append($"Server Performance Monitor - Not running. To start use /serverperformance start{'\n'}"); sb.Append($"World DB Cache Counts - Weenies: {DatabaseManager.World.GetWeenieCacheCount():N0}, LandblockInstances: {DatabaseManager.World.GetLandblockInstancesCacheCount():N0}, PointsOfInterest: {DatabaseManager.World.GetPointsOfInterestCacheCount():N0}, Cookbooks: {DatabaseManager.World.GetCookbookCacheCount():N0}, Spells: {DatabaseManager.World.GetSpellCacheCount():N0}, Encounters: {DatabaseManager.World.GetEncounterCacheCount():N0}, Events: {DatabaseManager.World.GetEventsCacheCount():N0}{'\n'}"); sb.Append($"Shard DB Counts - Biotas: {DatabaseManager.Shard.GetBiotaCount():N0}{'\n'}"); @@ -2072,6 +2074,43 @@ public static void HandleServerStatus(Session session, params string[] parameter CommandHandlerHelper.WriteOutputInfo(session, $"{sb}"); } + // serverstatus + [CommandHandler("serverperformance", AccessLevel.Advocate, CommandHandlerFlag.None, 0, "Displays a summary of server performance statistics")] + public static void HandleServerPerformance(Session session, params string[] parameters) + { + if (parameters != null && parameters.Length == 1) + { + if (parameters[0].ToLower() == "start") + { + ServerPerformanceMonitor.Start(); + CommandHandlerHelper.WriteOutputInfo(session, "Server Performance Monitor started"); + return; + } + + if (parameters[0].ToLower() == "stop") + { + ServerPerformanceMonitor.Stop(); + CommandHandlerHelper.WriteOutputInfo(session, "Server Performance Monitor stopped"); + return; + } + + if (parameters[0].ToLower() == "reset") + { + ServerPerformanceMonitor.Reset(); + CommandHandlerHelper.WriteOutputInfo(session, "Server Performance Monitor reset"); + return; + } + } + + if (!ServerPerformanceMonitor.IsRunning) + { + CommandHandlerHelper.WriteOutputInfo(session, "Server Performance Monitor not running. To start use /serverperformance start"); + return; + } + + CommandHandlerHelper.WriteOutputInfo(session, ServerPerformanceMonitor.ToString()); + } + [CommandHandler("modifybool", AccessLevel.Admin, CommandHandlerFlag.None, 2, "Modifies a server property that is a bool", "modifybool (string) (bool)")] public static void HandleModifyServerBoolProperty(Session session, params string[] paramters) { diff --git a/Source/ACE.Server/Config.js.example b/Source/ACE.Server/Config.js.example index a8fe93af33..90895ea9f6 100644 --- a/Source/ACE.Server/Config.js.example +++ b/Source/ACE.Server/Config.js.example @@ -16,6 +16,7 @@ }, "DatFilesDirectory": "c:\\ACE\\", "ShutdownInterval": "60", + "ServerPerformanceMonitorAutoStart": false, "WorldDatabasePrecaching": false, "LandblockPreloading": true, "PreloadedLandblocks": [ diff --git a/Source/ACE.Server/Entity/Landblock.cs b/Source/ACE.Server/Entity/Landblock.cs index 8ab7a62881..5d51897b5b 100644 --- a/Source/ACE.Server/Entity/Landblock.cs +++ b/Source/ACE.Server/Entity/Landblock.cs @@ -306,15 +306,20 @@ private void LoadScenery() public void Tick(double currentUnixTime) { + ServerPerformanceMonitor.ResumeEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_RunActions); actionQueue.RunActions(); + ServerPerformanceMonitor.PauseEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_RunActions); ProcessPendingWorldObjectAdditionsAndRemovals(); // When a WorldObject Ticks, it can end up adding additional WorldObjects to this landblock + ServerPerformanceMonitor.ResumeEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Player_Tick); foreach (var player in players) player.Player_Tick(currentUnixTime); + ServerPerformanceMonitor.PauseEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Player_Tick); + ServerPerformanceMonitor.ResumeEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Monster_Tick); while (sortedCreaturesByNextTick.Count > 0) // Monster_Tick() { var first = sortedCreaturesByNextTick.First.Value; @@ -331,7 +336,9 @@ public void Tick(double currentUnixTime) break; } } + ServerPerformanceMonitor.PauseEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Monster_Tick); + ServerPerformanceMonitor.ResumeEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_WorldObject_Heartbeat); while (sortedWorldObjectsByNextHeartbeat.Count > 0) // Heartbeat() { var first = sortedWorldObjectsByNextHeartbeat.First.Value; @@ -348,7 +355,9 @@ public void Tick(double currentUnixTime) break; } } + ServerPerformanceMonitor.PauseEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_WorldObject_Heartbeat); + ServerPerformanceMonitor.ResumeEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_GeneratorHeartbeat); while (sortedGeneratorsByNextGeneratorHeartbeat.Count > 0) // GeneratorHeartbeat() { var first = sortedGeneratorsByNextGeneratorHeartbeat.First.Value; @@ -365,8 +374,10 @@ public void Tick(double currentUnixTime) break; } } + ServerPerformanceMonitor.PauseEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_GeneratorHeartbeat); // Heartbeat + ServerPerformanceMonitor.ResumeEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Heartbeat); if (lastHeartBeat + heartbeatInterval <= DateTime.UtcNow) { var thisHeartBeat = DateTime.UtcNow; @@ -385,8 +396,10 @@ public void Tick(double currentUnixTime) lastHeartBeat = thisHeartBeat; } + ServerPerformanceMonitor.PauseEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Heartbeat); // Database Save + ServerPerformanceMonitor.ResumeEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Database_Save); if (lastDatabaseSave + databaseSaveInterval <= DateTime.UtcNow) { ProcessPendingWorldObjectAdditionsAndRemovals(); @@ -394,6 +407,7 @@ public void Tick(double currentUnixTime) SaveDB(); lastDatabaseSave = DateTime.UtcNow; } + ServerPerformanceMonitor.PauseEvent(ServerPerformanceMonitor.MonitorType.Landblock_Tick_Database_Save); } private void ProcessPendingWorldObjectAdditionsAndRemovals() diff --git a/Source/ACE.Server/Managers/ServerPerformanceMonitor.cs b/Source/ACE.Server/Managers/ServerPerformanceMonitor.cs new file mode 100644 index 0000000000..38fe1be5f7 --- /dev/null +++ b/Source/ACE.Server/Managers/ServerPerformanceMonitor.cs @@ -0,0 +1,258 @@ +using System; +using System.Text; + +using ACE.Common; + +namespace ACE.Server.Managers +{ + public static class ServerPerformanceMonitor + { + public static bool IsRunning; + + + public enum MonitorType + { + // These are all found in WorldManager.UpdateWorld() + PlayerManager_Tick, + InboundClientMessageQueue_RunActions, + actionQueue_RunActions, + DelayManager_RunActions, + UpdateGameWorld, + DoSessionWork, + + // These are all found in WorldManager.UpdateGameWorld() + UpdateGameWorld_Entire, + UpdateGameWorld_HandlePhysics, + UpdateGameWorld_RelocateObjectForPhysics, + UpdateGameWorld_landblock_Tick, + + // These are all found in Landblock.Tick() + Landblock_Tick_RunActions, + Landblock_Tick_Player_Tick, + Landblock_Tick_Monster_Tick, + Landblock_Tick_WorldObject_Heartbeat, + Landblock_Tick_GeneratorHeartbeat, + Landblock_Tick_Heartbeat, + Landblock_Tick_Database_Save, + + // These are all found in WorldManager.DoSessionWork() + DoSessionWork_TickInbound, + DoSessionWork_TickOutbound, + DoSessionWork_RemoveSessions, + + MonitorMaxItems // Keep this at the end to properly size our monitors array + } + + private static readonly RateMonitor[] monitors5m = new RateMonitor[(int)MonitorType.MonitorMaxItems]; + private static readonly RateMonitor[] monitors1h = new RateMonitor[(int)MonitorType.MonitorMaxItems]; + private static readonly RateMonitor[] monitors24h = new RateMonitor[(int)MonitorType.MonitorMaxItems]; + + private static readonly TimeSpan last5mClearInterval = TimeSpan.FromMinutes(5); + private static readonly TimeSpan last1hClearInteval = TimeSpan.FromHours(1); + private static readonly TimeSpan last24hClearInterval = TimeSpan.FromHours(24); + + private static DateTime last5mClear; + private static DateTime last1hClear; + private static DateTime last24hClear; + + private static TimeSpan Monitors5mRunTime => DateTime.UtcNow - last5mClear; + private static TimeSpan Monitors1hRunTime => DateTime.UtcNow - last1hClear; + private static TimeSpan Monitors24hRunTime => DateTime.UtcNow - last24hClear; + + + static ServerPerformanceMonitor() + { + for (int i = 0; i < monitors5m.Length; i++) + { + monitors5m[i] = new RateMonitor(); + monitors1h[i] = new RateMonitor(); + monitors24h[i] = new RateMonitor(); + } + } + + + public static void Start() + { + if (IsRunning) + return; + + Reset(); + + IsRunning = true; + } + + public static void Stop() + { + if (!IsRunning) + return; + + IsRunning = false; + } + + public static void Tick() + { + if (!IsRunning) + return; + + // check to see if we should clear history + if (DateTime.UtcNow - last5mClear >= last5mClearInterval) + { + foreach (var monitor in monitors5m) + monitor.ClearEventHistory(); + + last5mClear = DateTime.UtcNow; + } + + if (DateTime.UtcNow - last1hClear >= last1hClearInteval) + { + foreach (var monitor in monitors1h) + monitor.ClearEventHistory(); + + last1hClear = DateTime.UtcNow; + } + + if (DateTime.UtcNow - last24hClear >= last24hClearInterval) + { + foreach (var monitor in monitors24h) + monitor.ClearEventHistory(); + + last24hClear = DateTime.UtcNow; + } + } + + public static void Reset() + { + if (!IsRunning) + return; + + for (int i = 0; i < monitors5m.Length; i++) + { + monitors5m[i].ClearEventHistory(); + monitors1h[i].ClearEventHistory(); + monitors24h[i].ClearEventHistory(); + } + + last5mClear = DateTime.UtcNow; + last1hClear = DateTime.UtcNow; + last24hClear = DateTime.UtcNow; + } + + + public static void RegisterEventStart(MonitorType monitorType) + { + if (!IsRunning) + return; + + monitors24h[(int)monitorType].RegisterEventStart(); + monitors1h[(int)monitorType].RegisterEventStart(); + monitors5m[(int)monitorType].RegisterEventStart(); + + // Reset cumulative monitors + if (monitorType == MonitorType.UpdateGameWorld_Entire) + { + for (int i = (int) MonitorType.Landblock_Tick_RunActions; i <= (int) MonitorType.Landblock_Tick_Database_Save; i++) + { + monitors5m[i].ResetEvent(); + monitors1h[i].ResetEvent(); + monitors24h[i].ResetEvent(); + } + } + } + + public static void RegisterEventEnd(MonitorType monitorType) + { + if (!IsRunning) + return; + + monitors5m[(int)monitorType].RegisterEventEnd(); + monitors1h[(int)monitorType].RegisterEventEnd(); + monitors24h[(int)monitorType].RegisterEventEnd(); + + // Register end for cumulative monitors + if (monitorType == MonitorType.UpdateGameWorld_Entire) + { + for (int i = (int)MonitorType.Landblock_Tick_RunActions; i <= (int)MonitorType.Landblock_Tick_Database_Save; i++) + { + monitors5m[i].RegisterEventEnd(); + monitors1h[i].RegisterEventEnd(); + monitors24h[i].RegisterEventEnd(); + } + } + } + + + public static void ResumeEvent(MonitorType monitorType) + { + if (!IsRunning) + return; + + monitors24h[(int)monitorType].ResumeEvent(); + monitors1h[(int)monitorType].ResumeEvent(); + monitors5m[(int)monitorType].ResumeEvent(); + } + + public static void PauseEvent(MonitorType monitorType) + { + if (!IsRunning) + return; + + monitors5m[(int)monitorType].PauseEvent(); + monitors1h[(int)monitorType].PauseEvent(); + monitors24h[(int)monitorType].PauseEvent(); + } + + + public static RateMonitor GetMonitor5m(MonitorType monitorType) + { + return monitors5m[(int) monitorType]; + } + + public static RateMonitor GetMonitor1h(MonitorType monitorType) + { + return monitors1h[(int)monitorType]; + } + + public static RateMonitor GetMonitor24h(MonitorType monitorType) + { + return monitors24h[(int)monitorType]; + } + + + public new static string ToString() + { + var sb = new StringBuilder(); + + sb.Append($"Monitoring Durations: ~5m {Monitors5mRunTime.TotalMinutes:N2} min, ~1h {Monitors1hRunTime.TotalMinutes:N2} min, ~24h {Monitors24hRunTime.TotalMinutes:N2} min{'\n'}"); + sb.Append($"~5m Hits Avg Long Last - ~1h Hits Avg Long Last - ~24h Hits Avg Long Last (s) - Name{'\n'}"); + + sb.Append($"Calls from WorldManager.UpdateWorld(){'\n'}"); + for (int i = (int)MonitorType.PlayerManager_Tick; i <= (int)MonitorType.DoSessionWork; i++) + AddMonitorOutputToStringBuilder(monitors5m[i], monitors1h[i], monitors24h[i], (MonitorType)i, sb); + + sb.Append($"WorldManager.UpdateGameWorld() time not including throttled returns{'\n'}"); + AddMonitorOutputToStringBuilder(monitors5m[(int)MonitorType.UpdateGameWorld_Entire], monitors1h[(int)MonitorType.UpdateGameWorld_Entire], monitors24h[(int)MonitorType.UpdateGameWorld_Entire], MonitorType.UpdateGameWorld_Entire, sb); + + sb.Append($"Calls from WorldManager.UpdateGameWorld(){'\n'}"); + for (int i = (int)MonitorType.UpdateGameWorld_HandlePhysics; i <= (int)MonitorType.UpdateGameWorld_landblock_Tick; i++) + AddMonitorOutputToStringBuilder(monitors5m[i], monitors1h[i], monitors24h[i], (MonitorType)i, sb); + + sb.Append($"Calls from Landblock.Tick() - Cumulative over a single UpdateGameWorld Tick{'\n'}"); + for (int i = (int)MonitorType.Landblock_Tick_RunActions; i <= (int)MonitorType.Landblock_Tick_Database_Save; i++) + AddMonitorOutputToStringBuilder(monitors5m[i], monitors1h[i], monitors24h[i], (MonitorType)i, sb); + + sb.Append($"Calls from WorldManager.DoSessionWork(){'\n'}"); + for (int i = (int)MonitorType.DoSessionWork_TickInbound; i <= (int)MonitorType.DoSessionWork_RemoveSessions; i++) + AddMonitorOutputToStringBuilder(monitors5m[i], monitors1h[i], monitors24h[i], (MonitorType)i, sb); + + return sb.ToString(); + } + + private static void AddMonitorOutputToStringBuilder(RateMonitor monitor5m, RateMonitor monitor1h, RateMonitor monitor24h, MonitorType monitorType, StringBuilder sb) + { + sb.Append($"{monitor5m.TotalEvents.ToString().PadLeft(7)} {monitor5m.AverageEventDuration:N4} {monitor5m.LongestEvent:N3} {monitor5m.LastEvent:N3} - " + + $"{monitor1h.TotalEvents.ToString().PadLeft(7)} {monitor1h.AverageEventDuration:N4} {monitor1h.LongestEvent:N3} {monitor1h.LastEvent:N3} - " + + $"{monitor24h.TotalEvents.ToString().PadLeft(7)} {monitor24h.AverageEventDuration:N4} {monitor24h.LongestEvent:N3} {monitor24h.LastEvent:N3} - " + + $"{monitorType}{'\n'}"); + } + } +} diff --git a/Source/ACE.Server/Managers/WorldManager.cs b/Source/ACE.Server/Managers/WorldManager.cs index 5e79ded19c..c603055018 100644 --- a/Source/ACE.Server/Managers/WorldManager.cs +++ b/Source/ACE.Server/Managers/WorldManager.cs @@ -32,7 +32,7 @@ namespace ACE.Server.Managers { - public class WorldManager + public static class WorldManager { private static readonly ILog log = LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType); private static readonly ILog packetLog = LogManager.GetLogger(System.Reflection.Assembly.GetEntryAssembly(), "Packets"); @@ -519,18 +519,32 @@ private static void UpdateWorld() worldTickTimer.Restart(); + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.PlayerManager_Tick); PlayerManager.Tick(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.PlayerManager_Tick); + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.InboundClientMessageQueue_RunActions); InboundClientMessageQueue.RunActions(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.InboundClientMessageQueue_RunActions); // This will consist of PlayerEnterWorld actions, as well as other game world actions that require thread safety + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.actionQueue_RunActions); actionQueue.RunActions(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.actionQueue_RunActions); + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.DelayManager_RunActions); DelayManager.RunActions(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.DelayManager_RunActions); + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.UpdateGameWorld); var gameWorldUpdated = UpdateGameWorld(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.UpdateGameWorld); + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.DoSessionWork); int sessionCount = DoSessionWork(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.DoSessionWork); + + ServerPerformanceMonitor.Tick(); // We only relax the CPU if our game world is able to update at the target rate. // We do not sleep if our game world just updated. This is to prevent the scenario where our game world can't keep up. We don't want to add further delays. @@ -545,11 +559,6 @@ private static void UpdateWorld() WorldActive = false; } - public static readonly RateMonitor UpdateGameWorld5MinRM = new RateMonitor(); - public static DateTime UpdateGameWorld5MinLastReset = DateTime.UtcNow; - public static readonly RateMonitor UpdateGameWorld60MinRM = new RateMonitor(); - public static DateTime UpdateGameWorld60MinLastReset = DateTime.UtcNow; - /// /// Projected to run at a reasonable rate for gameplay (30-60fps) /// @@ -560,13 +569,15 @@ public static bool UpdateGameWorld() updateGameWorldRateLimiter.RegisterEvent(); - UpdateGameWorld5MinRM.RegisterEventStart(); - UpdateGameWorld60MinRM.RegisterEventStart(); + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_Entire); // update positions through physics engine + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_HandlePhysics); var movedObjects = HandlePhysics(Timers.PortalYearTicks); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_HandlePhysics); // iterate through objects that have changed landblocks + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_RelocateObjectForPhysics); foreach (var movedObject in movedObjects) { // NOTE: The object's Location can now be null, if a player logs out, or an item is picked up @@ -575,33 +586,23 @@ public static bool UpdateGameWorld() // assume adjacency move here? LandblockManager.RelocateObjectForPhysics(movedObject, true); } + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_RelocateObjectForPhysics); // Tick all of our Landblocks and WorldObjects + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_landblock_Tick); var activeLandblocks = LandblockManager.GetActiveLandblocks(); foreach (var landblock in activeLandblocks) landblock.Tick(Time.GetUnixTime()); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_landblock_Tick); // clean up inactive landblocks LandblockManager.UnloadLandblocks(); - UpdateGameWorld5MinRM.RegisterEventEnd(); - UpdateGameWorld60MinRM.RegisterEventEnd(); - - if (UpdateGameWorld5MinRM.TotalSeconds > 300) - { - UpdateGameWorld5MinRM.ClearEventHistory(); - UpdateGameWorld5MinLastReset = DateTime.UtcNow; - } - - if (UpdateGameWorld60MinRM.TotalSeconds > 3600) - { - UpdateGameWorld60MinRM.ClearEventHistory(); - UpdateGameWorld60MinLastReset = DateTime.UtcNow; - } - HouseManager.Tick(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.UpdateGameWorld_Entire); + return true; } @@ -705,16 +706,21 @@ public static int DoSessionWork() sessionCount = sessions.Count; // The session tick inbound processes all inbound GameAction messages + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.DoSessionWork_TickInbound); foreach (var s in sessions) s.TickInbound(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.DoSessionWork_TickInbound); // Do not combine the above and below loops. All inbound messages should be processed first and then all outbound messages should be processed second. // The session tick outbound processes pending actions and handles outgoing messages + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.DoSessionWork_TickOutbound); foreach (var s in sessions) s.TickOutbound(); + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.DoSessionWork_TickOutbound); // Removes sessions in the NetworkTimeout state, including sessions that have reached a timeout limit. + ServerPerformanceMonitor.RegisterEventStart(ServerPerformanceMonitor.MonitorType.DoSessionWork_RemoveSessions); for (int i = sessions.Count - 1; i >= 0; i--) { var sesh = sessions[i]; @@ -728,6 +734,7 @@ public static int DoSessionWork() break; } } + ServerPerformanceMonitor.RegisterEventEnd(ServerPerformanceMonitor.MonitorType.DoSessionWork_RemoveSessions); } finally { diff --git a/Source/ACE.Server/Program.cs b/Source/ACE.Server/Program.cs index d9919d37f0..1d93d03923 100644 --- a/Source/ACE.Server/Program.cs +++ b/Source/ACE.Server/Program.cs @@ -82,6 +82,12 @@ public static void Main(string[] args) log.Info("Initializing GuidManager..."); GuidManager.Initialize(); + if (ConfigManager.Config.Server.ServerPerformanceMonitorAutoStart) + { + log.Info("Server Performance Monitor auto starting..."); + ServerPerformanceMonitor.Start(); + } + if (ConfigManager.Config.Server.WorldDatabasePrecaching) { log.Info("Precaching Weenies..."); diff --git a/changelog.md b/changelog.md index 5d077d0344..40016b05de 100644 --- a/changelog.md +++ b/changelog.md @@ -4,6 +4,10 @@ [Ripley] * Fix to prevent multiple death stacking. You can only die one time until you resurrect at lifestone. +### 2019-04-03 +[Mag-nus] +* /serverperformance command added. Optional parameters: start, stop, reset + ### 2019-04-02 [Ripley] * Change the way GiveObjecttoNPC and HandleNPCReceiveItem deal with emotes.