diff --git a/2006Scape Server/ServerConfig.Sample.json b/2006Scape Server/ServerConfig.Sample.json index 9acb39e8..473fbe21 100644 --- a/2006Scape Server/ServerConfig.Sample.json +++ b/2006Scape Server/ServerConfig.Sample.json @@ -23,5 +23,7 @@ "timeout": 60, "item_requirements": true, "max_players": 200, - "website_integration": false + "website_integration": false, + "cycle_logging": true, + "cycle_logging_tick": 10 } \ No newline at end of file diff --git a/2006Scape Server/src/main/java/com/rs2/ConfigLoader.java b/2006Scape Server/src/main/java/com/rs2/ConfigLoader.java index d4202cf0..710afd9d 100644 --- a/2006Scape Server/src/main/java/com/rs2/ConfigLoader.java +++ b/2006Scape Server/src/main/java/com/rs2/ConfigLoader.java @@ -72,6 +72,11 @@ public class ConfigLoader { } if (obj.has("website_integration")) Constants.WEBSITE_INTEGRATION = obj.getBoolean("website_integration"); + + if (obj.has("cycle_logging")) + Constants.CYCLE_LOGGING = obj.getBoolean("cycle_logging"); + if (obj.has("cycle_logging_tick")) + Constants.CYCLE_LOGGING_TICK = obj.getInt("cycle_logging_tick"); } private static void initialize() { diff --git a/2006Scape Server/src/main/java/com/rs2/Constants.java b/2006Scape Server/src/main/java/com/rs2/Constants.java index d04a2d91..1cca2d30 100644 --- a/2006Scape Server/src/main/java/com/rs2/Constants.java +++ b/2006Scape Server/src/main/java/com/rs2/Constants.java @@ -39,11 +39,11 @@ public class Constants { * WEBSITE_INTEGRATION Enables/Disables Website Features(Total Accounts Registered & Players Online) */ public static String SERVER_NAME = "2006Scape", WEBSITE_LINK = "https://2006Scape.org"; - public static int WORLD = 1, HTTP_PORT = 8080, JAGGRAB_PORT = 43595, MAX_PLAYERS = 200, SAVE_TIMER = 120, TIMEOUT = 60, RESPAWN_X = 3222, RESPAWN_Y = 3218; + public static int WORLD = 1, HTTP_PORT = 8080, JAGGRAB_PORT = 43595, MAX_PLAYERS = 200, SAVE_TIMER = 120, TIMEOUT = 60, RESPAWN_X = 3222, RESPAWN_Y = 3218, CYCLE_LOGGING_TICK = 10; public static boolean GUI_ENABLED = false, FILE_SERVER = true, SERVER_DEBUG = false, MEMBERS_ONLY = false, TUTORIAL_ISLAND = false, PARTY_ROOM_DISABLED = false, CLUES_ENABLED = true, ITEM_REQUIREMENTS = true, ADMIN_CAN_TRADE = false, ADMIN_DROP_ITEMS = false, ADMIN_CAN_SELL_ITEMS = false, VARIABLE_XP_RATE = false, - WEBSITE_INTEGRATION = false; + WEBSITE_INTEGRATION = false, CYCLE_LOGGING = true; public static int[] VARIABLE_XP_RATES = new int[] {1, 2, 5, 10}; public static double TEST_VERSION = 2.3, XP_RATE = 1.0; diff --git a/2006Scape Server/src/main/java/com/rs2/GameEngine.java b/2006Scape Server/src/main/java/com/rs2/GameEngine.java index 761015d5..bb1c132e 100644 --- a/2006Scape Server/src/main/java/com/rs2/GameEngine.java +++ b/2006Scape Server/src/main/java/com/rs2/GameEngine.java @@ -13,6 +13,9 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReentrantLock; +import com.google.common.base.Stopwatch; +import com.rs2.game.npcs.Npc; +import com.rs2.game.npcs.NpcList; import com.rs2.gui.ControlPanel; import org.apollo.cache.IndexedFileSystem; @@ -239,8 +242,10 @@ public class GameEngine { * scheduleAtFixedRate() does not invoke concurrent Runnables. */ scheduler.scheduleAtFixedRate(new Runnable() { + int gameTicksIncrementor; + final int printInfoTick = Constants.CYCLE_LOGGING_TICK; public void run() { - //TODO debug Stopwatch stopwatch = Stopwatch.createStarted(); + Stopwatch stopwatch = Stopwatch.createStarted(); /** * Main Server Tick */ @@ -248,17 +253,51 @@ public class GameEngine { if (GameEngine.shutdownServer) { scheduler.shutdown(); } + long startItemHandler = System.currentTimeMillis(); itemHandler.process(); + long durationItemHandler = System.currentTimeMillis() - startItemHandler; + checkAndLogDuration("ItemHandler", durationItemHandler); + long startPlayerHandler = System.currentTimeMillis(); playerHandler.process(); + long durationPlayerHandler = System.currentTimeMillis() - startPlayerHandler; + checkAndLogDuration("PlayerHandler", durationPlayerHandler); + long startNpcHandler = System.currentTimeMillis(); npcHandler.process(); + long durationNpcHandler = System.currentTimeMillis() - startNpcHandler; + checkAndLogDuration("NpcHandler", durationNpcHandler); + long startShopHandler = System.currentTimeMillis(); shopHandler.process(); + long durationShopHandler = System.currentTimeMillis() - startShopHandler; + checkAndLogDuration("ShopHandler", durationShopHandler); + long startObjectManager = System.currentTimeMillis(); objectManager.process(); + long durationObjectManager = System.currentTimeMillis() - startObjectManager; + checkAndLogDuration("ObjectManager", durationObjectManager); + long startCastleWars = System.currentTimeMillis(); CastleWars.process(); + long durationCastleWars = System.currentTimeMillis() - startCastleWars; + checkAndLogDuration("CastleWars", durationCastleWars); + long startFightPits = System.currentTimeMillis(); FightPits.process(); + long durationFightPits = System.currentTimeMillis() - startFightPits; + checkAndLogDuration("FightPits", durationFightPits); + long startPestControl = System.currentTimeMillis(); pestControl.process(); + long durationPestControl = System.currentTimeMillis() - startPestControl; + checkAndLogDuration("PestControl", durationPestControl); + long startObjectHandler = System.currentTimeMillis(); objectHandler.process(); + long durationObjectHandler = System.currentTimeMillis() - startObjectHandler; + checkAndLogDuration("CastleWars", durationObjectHandler); + long startMageTrainingArena = System.currentTimeMillis(); MageTrainingArena.process(); + long durationMageTrainingArena = System.currentTimeMillis() - startMageTrainingArena; + checkAndLogDuration("MageTrainingArena", durationMageTrainingArena); + long startCycleEventHandler = System.currentTimeMillis(); CycleEventHandler.getSingleton().process(); + long durationCycleEventHandler = System.currentTimeMillis() - startCycleEventHandler; + checkAndLogDuration("CycleEventHandler", durationCycleEventHandler); + long startIntegrationEvents = System.currentTimeMillis(); if (Constants.WEBSITE_INTEGRATION) { PlayersOnlineWebsite.addUpdatePlayersOnlineTask(); RegisteredAccsWebsite.addUpdateRegisteredUsersTask(); @@ -266,6 +305,9 @@ public class GameEngine { if (DiscordActivity.playerCount) { DiscordActivity.updateActivity(); } + long durationIntegrationEvents = System.currentTimeMillis() - startIntegrationEvents; + checkAndLogDuration("IntegrationEvents", durationIntegrationEvents); + long startSaveEvents = System.currentTimeMillis(); if (System.currentTimeMillis() - lastMassSave > 300000) { for (Player p : PlayerHandler.players) { if (p == null) { @@ -276,9 +318,42 @@ public class GameEngine { lastMassSave = System.currentTimeMillis(); } } + long durationSaveEvents = System.currentTimeMillis() - startSaveEvents; + checkAndLogDuration("SaveEvents", durationSaveEvents); + long totalCycleDuration = stopwatch.elapsed(TimeUnit.MILLISECONDS); + //Technically, we could add commands to test both client lag (creating many tile objects) and server lag (creating a BCrypt hash on game thread) + if (totalCycleDuration > 500) { + System.err.println("ERROR: Cycle duration exceeded 500 ms!"); + } else if (totalCycleDuration > 250) { + System.err.println("WARNING: Cycle duration exceeded 250 ms!"); + } else if (totalCycleDuration > 100) { + System.out.println("NOTICE: Cycle duration exceeded 100 ms."); + } + gameTicksIncrementor++; + if (Constants.CYCLE_LOGGING && gameTicksIncrementor > 1 && gameTicksIncrementor % printInfoTick == 0) { + long totalMem = Runtime.getRuntime().totalMemory(); + long freeMem = Runtime.getRuntime().freeMemory(); + long maxMem = Runtime.getRuntime().maxMemory(); + int playerCount = 0; + for (Player p : PlayerHandler.players) { + if (p != null) { + playerCount++; + } + } + int npcCount = 0; + for (Npc npc : NpcHandler.npcs) { + if (npc != null) { + npcCount++; + } + } + System.out.println("Cycle #" + gameTicksIncrementor + " took " + totalCycleDuration + " ms. Players: " + playerCount + ", NPCs: " + npcCount + + ", [Durations: i: " + durationItemHandler + " ms, p: " + durationPlayerHandler + " ms, n: " + durationNpcHandler + " ms, s: " + durationShopHandler + + " ms, oh: " + durationObjectHandler + " ms, om: " + durationObjectManager + " ms], Memory: " + (totalMem - freeMem) / 1024 / 1024 + "MB/" + + totalMem / 1024 / 1024 + "MB. Max: " + maxMem / 1024 / 1024 + "MB, Threads: " + Thread.activeCount() + "."); + } } catch (Exception ex) { ex.printStackTrace(); - System.out.println("A fatal exception has been thrown!"); + System.err.println("A fatal exception has been thrown in the GameEngine cycle! Saving all players."); for (Player p : PlayerHandler.players) { if (p == null) { continue; @@ -294,7 +369,6 @@ public class GameEngine { } scheduler.shutdown(); // Kills the tickloop thread if Exception is thrown. } - //TODO debug System.out.println("Cycle took " + stopwatch.elapsed(TimeUnit.MILLISECONDS) + " ms."); } }, 0, Constants.CYCLE_TIME, TimeUnit.MILLISECONDS); @@ -315,6 +389,16 @@ public class GameEngine { System.exit(0); } + + private static void checkAndLogDuration(String processName, long duration) { + if (duration > 500) { + System.err.println("ERROR: " + processName + " duration exceeded 500 ms! Duration: " + duration + " ms."); + } else if (duration > 250) { + System.err.println("WARNING: " + processName + " duration exceeded 250 ms! Duration: " + duration + " ms."); + } else if (duration > 100) { + System.out.println("NOTICE: " + processName + " duration exceeded 100 ms. Duration: " + duration + " ms."); + } + } public static boolean playerExecuted = false; private static BufferedReader minuteFile;