Implement some basic benchmarking for seed generation (#4353)

* messy first implementation, pushing for verification

* push to test other platforms, add benchmark preset

* more other compiler fixes

* Finish implementing benchmarks

* forgot to reset the timers each run

* do it better

* move timers to thier own file

* forgot to add files

soh/soh/Enhancements/debugger/performanceTimer.cpp

@@ -0,0 +1,19 @@
+#pragma once
+
+#include "performanceTimer.h"
+
+void StartPerformanceTimer(TimerID timer){
+    timeStarted[timer] = std::chrono::high_resolution_clock::now();
+}
+
+void StopPerformanceTimer(TimerID timer){
+    totalTimes[timer] += (std::chrono::high_resolution_clock::now() - timeStarted[timer]);
+}
+
+std::chrono::duration<double, std::milli> GetPerformanceTimer(TimerID timer){
+    return totalTimes[timer];
+}
+
+void ResetPerformanceTimers(){
+    totalTimes = {};
+}

soh/soh/Enhancements/debugger/performanceTimer.h

@@ -0,0 +1,38 @@
+#pragma once
+
+#include <vector>
+#include <array>
+#include <chrono>
+
+typedef enum {
+  PT_WHOLE_SEED,
+  PT_LOGIC_RESET,
+  PT_AREA_RESET,
+  PT_UPDATE_HELPERS,
+  PT_SPOILER_LOG,
+  PT_ENTRANCE_SHUFFLE,
+  PT_SHOPSANITY,
+  PT_OWN_DUNGEON,
+  PT_LIMITED_CHECKS,
+  PT_ADVANCEMENT_ITEMS,
+  PT_REMAINING_ITEMS,
+  PT_PLAYTHROUGH_GENERATION,
+  PT_PARE_DOWN_PLAYTHROUGH,
+  PT_WOTH,
+  PT_FOOLISH,
+  PT_OVERRIDES,
+  PT_HINTS,
+  PT_EVENT_ACCESS,
+  PT_TOD_ACCESS,
+  PT_ENTRANCE_LOGIC,
+  PT_LOCATION_LOGIC,
+  PT_MAX
+} TimerID;
+
+void StartPerformanceTimer(TimerID timer);
+void StopPerformanceTimer(TimerID timer);
+std::chrono::duration<double, std::milli> GetPerformanceTimer(TimerID timer);
+void ResetPerformanceTimers();
+static std::array<std::chrono::duration<double, std::milli>, PT_MAX> totalTimes = {};
+static std::array<std::chrono::high_resolution_clock::time_point, PT_MAX> timeStarted = {};
+

soh/soh/Enhancements/presets.h

@@ -34,6 +34,7 @@ enum RandomizerPreset {
     RANDOMIZER_PRESET_SPOCK_RACE_NO_LOGIC,
     RANDOMIZER_PRESET_S6,
     RANDOMIZER_PRESET_HELL_MODE,
+    RANDOMIZER_PRESET_BENCHMARK,
 };
 
 typedef struct PresetEntry {
@@ -1147,6 +1148,122 @@ const std::vector<PresetEntry> hellModePresetEntries = {
     PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ZorasFountain"), 2),
 };
 
+const std::vector<PresetEntry> BenchmarkPresetEntries = {
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("Forest"), RO_FOREST_CLOSED_DEKU),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("KakarikoGate"), RO_KAK_GATE_OPEN),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("DoorOfTime"), RO_DOOROFTIME_SONGONLY),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ZorasFountain"), RO_ZF_CLOSED),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GerudoFortress"), RO_GF_NORMAL),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("RainbowBridge"), RO_BRIDGE_DUNGEON_REWARDS),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("RewardCount"), 5),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("BridgeRewardOptions"), RO_BRIDGE_GREG_REWARD),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GanonTrial"), RO_GANONS_TRIALS_SET_NUMBER),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GanonTrialCount"), 6),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingAge"), RO_AGE_RANDOM),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleDungeonsEntrances"), RO_DUNGEON_ENTRANCE_SHUFFLE_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleBossEntrances"), RO_BOSS_ROOM_ENTRANCE_SHUFFLE_FULL),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleOverworldEntrances"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleInteriorsEntrances"), RO_INTERIOR_ENTRANCE_SHUFFLE_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleGrottosEntrances"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleWarpSongs"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleOverworldSpawns"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("MixedEntrances"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("DecoupleEntrances"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("BombchusInLogic"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("EnableBombchuDrops"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("TriforceHunt"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("MQDungeons"), RO_MQ_DUNGEONS_RANDOM_NUMBER),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("MQDungeonsSelection"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleDungeonReward"), RO_DUNGEON_REWARDS_END_OF_DUNGEON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("LinksPocket"), RO_LINKS_POCKET_DUNGEON_REWARD),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleSongs"), RO_SONG_SHUFFLE_ANYWHERE),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("Shopsanity"), RO_SHOPSANITY_FOUR_ITEMS),
+    //RANDOTODO add refactored price/scrub/merchant settings
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleTokens"), RO_TOKENSANITY_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleBeehives"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleCows"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleKokiriSword"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleMasterSword"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleChildWallet"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleOcarinas"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleOcarinaButtons"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleSwim"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleGerudoToken"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleFrogSongRupees"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleAdultTrade"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("Shuffle100GSReward"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleBossSouls"), RO_BOSS_SOULS_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleDekuStickBag"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleDekuNutBag"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("Fishsanity"), RO_FISHSANITY_BOTH),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("FishsanityAgeSplit"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingMapsCompasses"), RO_DUNGEON_ITEM_LOC_OWN_DUNGEON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GerudoKeys"), RO_GERUDO_KEYS_ANYWHERE),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("BossKeysanity"), RO_DUNGEON_ITEM_LOC_OWN_DUNGEON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleGanonBossKey"), RO_GANON_BOSS_KEY_LACS_MEDALLIONS),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("LacsMedallionCount"), 6),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ShuffleKeyRings"), RO_KEYRINGS_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("SkipChildZelda"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("SkipEponaRace"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("SkipScarecrowsSong"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("BigPoeTargetCount"), 1),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("CuccosToReturn"), 4),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("CompleteMaskQuest"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GossipStoneHints"), RO_GOSSIP_STONES_NEED_NOTHING),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("HintClarity"), RO_HINT_CLARITY_CLEAR),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("HintDistribution"), RO_HINT_DIST_STRONG),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("AltarHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GanondorfHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("SheikLAHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("DampeHint"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GregHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("SariaHint"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("FrogsHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("OoTHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("BiggoronHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("BigPoesHint"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ChickensHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("MalonHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("HBAHint"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("WarpSongText"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ScrubText"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("10GSHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("20GSHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("30GSHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("40GSHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("50GSHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("MaskShopHint"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("BlueFireArrows"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("SunlightArrows"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("InfiniteUpgrades"), RO_INF_UPGRADES_PROGRESSIVE),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("SkeletonKey"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("ItemPool"), RO_ITEM_POOL_BALANCED),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("IceTraps"), RO_ICE_TRAPS_NORMAL),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingOcarina"), RO_STARTING_OCARINA_FAIRY),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingDekuShield"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingKokiriSword"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingMasterSword"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingConsumables"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("FullWallets"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingZeldasLullaby"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingEponasSong"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingSariasSong"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingSunsSong"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingSongOfTime"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingSongOfStorms"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingMinuetOfForest"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingBoleroOfFire"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingSerenadeOfWater"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingRequiemOfSpirit"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingNocturneOfShadow"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingPreludeOfLight"), RO_GENERIC_OFF),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("StartingSkulltulaToken"), 0),
+    PRESET_ENTRY_S32("gRandomizeStartingHearts", 2),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("LogicRules"), RO_LOGIC_GLITCHLESS),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("AllLocationsReachable"), RO_GENERIC_ON),
+    PRESET_ENTRY_S32(CVAR_RANDOMIZER_SETTING("GsExpectSunsSong"), RO_GENERIC_ON),
+};
+
 typedef struct PresetDefinition {
     const char* label;
     const char* description;
@@ -1220,5 +1337,10 @@ const std::map<PresetType, PresetTypeDefinition> presetTypes = {
             "All settings maxed but still using glitchless logic. Expect pain.",
             hellModePresetEntries
         } },
+        { RANDOMIZER_PRESET_BENCHMARK, {
+            "Benchmark",
+            "Used for benchmarking the logic.",
+            BenchmarkPresetEntries
+        } },
     } } }
 };

soh/soh/Enhancements/randomizer/3drando/fill.cpp

@@ -14,6 +14,7 @@
 #include "pool_functions.hpp"
 //#include "debug.hpp"
 #include "soh/Enhancements/randomizer/static_data.h"
+#include "../../debugger/performanceTimer.h"
 
 #include <vector>
 #include <list>
@@ -100,6 +101,7 @@ static void RemoveStartingItemsFromPool() {
 
 //This function will propagate Time of Day access through the entrance
 static bool UpdateToDAccess(Entrance* entrance, bool propagateTimeTravel) {
+  StartPerformanceTimer(PT_TOD_ACCESS);
 
   bool ageTimePropogated = false;
 
@@ -133,6 +135,7 @@ static bool UpdateToDAccess(Entrance* entrance, bool propagateTimeTravel) {
     AreaTable(RR_ROOT)->childNight = AreaTable(RR_TOT_BEYOND_DOOR_OF_TIME)->adultNight;
   }
 
+  StopPerformanceTimer(PT_TOD_ACCESS);
   return ageTimePropogated;
 }
 
@@ -360,6 +363,7 @@ void AddToPlaythrough(LocationAccess& locPair, GetAccessableLocationsStruct& gal
 // Adds the contents of a location to the current progression and optionally playthrough
 bool AddCheckToLogic(LocationAccess& locPair, GetAccessableLocationsStruct& gals, RandomizerGet ignore, bool stopOnBeatable, bool addToPlaythrough=false){
   auto ctx = Rando::Context::GetInstance();
+  StartPerformanceTimer(PT_LOCATION_LOGIC);
   RandomizerCheck loc = locPair.GetLocation();
   Rando::ItemLocation* location = ctx->GetItemLocation(loc);
   RandomizerGet locItem = location->GetPlacedRandomizerGet();
@@ -399,9 +403,11 @@ bool AddCheckToLogic(LocationAccess& locPair, GetAccessableLocationsStruct& gals
     }
     //All we care about is if the game is beatable, used to pare down playthrough
     if (location->GetPlacedRandomizerGet() == RG_TRIFORCE && stopOnBeatable) {
+      StopPerformanceTimer(PT_LOCATION_LOGIC);
       return true; //Return early for efficiency
     }
   }
+  StopPerformanceTimer(PT_LOCATION_LOGIC);
   return false;
 }
 
@@ -1149,6 +1155,7 @@ int Fill() {
 
     //Temporarily add shop items to the ItemPool so that entrance randomization
     //can validate the world using deku/hylian shields
+    StartPerformanceTimer(PT_ENTRANCE_SHUFFLE);
     AddElementsToPool(ItemPool, GetMinVanillaShopItems(32)); //assume worst case shopsanity 4
     if (ctx->GetOption(RSK_SHUFFLE_ENTRANCES)) {
       SPDLOG_INFO("Shuffling Entrances...");
@@ -1162,9 +1169,12 @@ int Fill() {
     SetAreas();
     //erase temporary shop items
     FilterAndEraseFromPool(ItemPool, [](const auto item) { return Rando::StaticData::RetrieveItem(item).GetItemType() == ITEMTYPE_SHOP; });
+    StopPerformanceTimer(PT_ENTRANCE_SHUFFLE);
 
     //ctx->showItemProgress = true;
     //Place shop items first, since a buy shield is needed to place a dungeon reward on Gohma due to access
+    
+    StartPerformanceTimer(PT_SHOPSANITY);
     NonShopItems = {};
     if (ctx->GetOption(RSK_SHOPSANITY).Is(RO_SHOPSANITY_OFF)) {
       SPDLOG_INFO("Placing Vanilla Shop Items...");
@@ -1211,7 +1221,9 @@ int Fill() {
       //Place the shop items which will still be at shop locations
       AssumedFill(shopItems, shopLocations);
     }
+    StopPerformanceTimer(PT_SHOPSANITY);
 
+    StartPerformanceTimer(PT_OWN_DUNGEON);
     //Place dungeon rewards
     SPDLOG_INFO("Shuffling and Placing Dungeon Items...");
     RandomizeDungeonRewards();
@@ -1220,7 +1232,9 @@ int Fill() {
     for (auto dungeon : ctx->GetDungeons()->GetDungeonList()) {
       RandomizeOwnDungeon(dungeon);
     }
+    StopPerformanceTimer(PT_OWN_DUNGEON);
 
+    StartPerformanceTimer(PT_LIMITED_CHECKS);
     //Then Place songs if song shuffle is set to specific locations
     if (ctx->GetOption(RSK_SHUFFLE_SONGS).IsNot(RO_SONG_SHUFFLE_ANYWHERE)) {
 
@@ -1249,16 +1263,23 @@ int Fill() {
 
     //Then place Link's Pocket Item if it has to be an advancement item
     RandomizeLinksPocket();
+    StopPerformanceTimer(PT_LIMITED_CHECKS);
+
+
+    StartPerformanceTimer(PT_ADVANCEMENT_ITEMS);
     SPDLOG_INFO("Shuffling Advancement Items");
     //Then place the rest of the advancement items
     std::vector<RandomizerGet> remainingAdvancementItems =
         FilterAndEraseFromPool(ItemPool, [](const auto i) { return Rando::StaticData::RetrieveItem(i).IsAdvancement(); });
     AssumedFill(remainingAdvancementItems, ctx->allLocations, true);
+    StopPerformanceTimer(PT_ADVANCEMENT_ITEMS);
 
+    StartPerformanceTimer(PT_REMAINING_ITEMS);
     //Fast fill for the rest of the pool
     SPDLOG_INFO("Shuffling Remaining Items");
     std::vector<RandomizerGet> remainingPool = FilterAndEraseFromPool(ItemPool, [](const auto i) { return true; });
     FastFill(remainingPool, GetAllEmptyLocations(), false);
+    StopPerformanceTimer(PT_REMAINING_ITEMS);
 
     //Add default prices to scrubs
     for (size_t i = 0; i < Rando::StaticData::scrubLocations.size(); i++) {
@@ -1284,19 +1305,35 @@ int Fill() {
       }
     }
 
+    StartPerformanceTimer(PT_PLAYTHROUGH_GENERATION);
     GeneratePlaythrough();
+    StopPerformanceTimer(PT_PLAYTHROUGH_GENERATION);
     //Successful placement, produced beatable result
     if(ctx->playthroughBeatable && !placementFailure) {
+
       SPDLOG_INFO("Calculating Playthrough...");
+      StartPerformanceTimer(PT_PARE_DOWN_PLAYTHROUGH);
       PareDownPlaythrough();
+      StopPerformanceTimer(PT_PARE_DOWN_PLAYTHROUGH);
+
+      StartPerformanceTimer(PT_WOTH);
       CalculateWotH();
+      StopPerformanceTimer(PT_WOTH);
+
+      StartPerformanceTimer(PT_FOOLISH);
       CalculateBarren(); 
+      StopPerformanceTimer(PT_FOOLISH);
       SPDLOG_INFO("Calculating Playthrough Done");
+
+      StartPerformanceTimer(PT_OVERRIDES);
       ctx->CreateItemOverrides();
       ctx->GetEntranceShuffler()->CreateEntranceOverrides();
-      
+      StopPerformanceTimer(PT_OVERRIDES);
+
+      StartPerformanceTimer(PT_HINTS);
       CreateAllHints();
       CreateWarpSongTexts();
+      StopPerformanceTimer(PT_HINTS);
       return 1;
     }
     //Unsuccessful placement

soh/soh/Enhancements/randomizer/3drando/location_access.cpp

@@ -7,6 +7,7 @@
 #include "spoiler_log.hpp"
 #include "../trial.h"
 #include "../entrance.h"
+#include "../../debugger/performanceTimer.h"
 
 #include <fstream>
 
@@ -91,6 +92,7 @@ Area::~Area() = default;
 
 bool Area::UpdateEvents(bool haveTimeAccess) {
   if (timePass && haveTimeAccess) {
+    StartPerformanceTimer(PT_TOD_ACCESS);
     if (Child()) {
       childDay = true;
       childNight = true;
@@ -103,11 +105,13 @@ bool Area::UpdateEvents(bool haveTimeAccess) {
       AreaTable(RR_ROOT)->adultDay = true;
       AreaTable(RR_ROOT)->adultNight = true;
     }
+    StopPerformanceTimer(PT_TOD_ACCESS);
   }
 
   bool eventsUpdated =  false;
-
+  StartPerformanceTimer(PT_EVENT_ACCESS);
   for (EventAccess& event : events) {
+    
     //If the event has already happened, there's no reason to check it
     if (event.GetEvent()) {
       continue;
@@ -121,6 +125,7 @@ bool Area::UpdateEvents(bool haveTimeAccess) {
           eventsUpdated = true;
     }
   }
+  StopPerformanceTimer(PT_EVENT_ACCESS);
   return eventsUpdated;
 }
 

soh/soh/Enhancements/randomizer/3drando/menu.cpp

@@ -10,6 +10,7 @@
 #include "randomizer.hpp"
 #include "spoiler_log.hpp"
 #include "location_access.hpp"
+#include "../../debugger/performanceTimer.h"
 #include <spdlog/spdlog.h>
 #include "../../randomizer/randomizerTypes.h"
 #include <boost_custom/container_hash/hash_32.hpp>
@@ -24,6 +25,8 @@ Rando::Option* currentSetting;
 bool GenerateRandomizer(std::set<RandomizerCheck> excludedLocations, std::set<RandomizerTrick> enabledTricks,
     std::string seedInput) {
     const auto ctx = Rando::Context::GetInstance();
+    ResetPerformanceTimers();
+    StartPerformanceTimer(PT_WHOLE_SEED);
 
     srand(time(NULL));
     // if a blank seed was entered, make a random one
@@ -65,5 +68,28 @@ bool GenerateRandomizer(std::set<RandomizerCheck> excludedLocations, std::set<Ra
         }
         ctx->GetOption(RSK_KEYSANITY).RestoreDelayedOption();
     }
+
+    StopPerformanceTimer(PT_WHOLE_SEED);
+    SPDLOG_DEBUG("Full Seed Genration Time: {}ms", GetPerformanceTimer(PT_WHOLE_SEED).count());
+    SPDLOG_DEBUG("LogicReset time: {}ms", GetPerformanceTimer(PT_LOGIC_RESET).count());
+    SPDLOG_DEBUG("Area->Reset time: {}ms", GetPerformanceTimer(PT_AREA_RESET).count());
+    SPDLOG_DEBUG("Total Entrance Shuffle time: {}ms", GetPerformanceTimer(PT_ENTRANCE_SHUFFLE).count());
+    SPDLOG_DEBUG("Total Shopsanity time: {}ms", GetPerformanceTimer(PT_SHOPSANITY).count());
+    SPDLOG_DEBUG("Total Dungeon Specific Items time: {}ms", GetPerformanceTimer(PT_OWN_DUNGEON).count());
+    SPDLOG_DEBUG("Total Misc Limited Checks time: {}ms", GetPerformanceTimer(PT_LIMITED_CHECKS).count());
+    SPDLOG_DEBUG("Total Advancment Checks time: {}ms", GetPerformanceTimer(PT_ADVANCEMENT_ITEMS).count());
+    SPDLOG_DEBUG("Total Other Checks time: {}ms", GetPerformanceTimer(PT_REMAINING_ITEMS).count());
+    SPDLOG_DEBUG("Total Playthrough Generation time: {}ms", GetPerformanceTimer(PT_PLAYTHROUGH_GENERATION).count());
+    SPDLOG_DEBUG("Total PareDownPlaythrough time: {}ms", GetPerformanceTimer(PT_PARE_DOWN_PLAYTHROUGH).count());
+    SPDLOG_DEBUG("Total WotH generation time: {}ms", GetPerformanceTimer(PT_WOTH).count());
+    SPDLOG_DEBUG("Total Foolish generation time: {}ms", GetPerformanceTimer(PT_FOOLISH).count());
+    SPDLOG_DEBUG("Total Overrides time: {}ms", GetPerformanceTimer(PT_OVERRIDES).count());
+    SPDLOG_DEBUG("Total Hint Generation time: {}ms", GetPerformanceTimer(PT_HINTS).count());
+    SPDLOG_DEBUG("SpoilerLog writing time: {}ms", GetPerformanceTimer(PT_SPOILER_LOG).count());
+    SPDLOG_DEBUG("Total UpdateHelpers time: {}ms", GetPerformanceTimer(PT_UPDATE_HELPERS).count());
+    SPDLOG_DEBUG("Total Event Access Calculation time: {}ms", GetPerformanceTimer(PT_EVENT_ACCESS).count());
+    SPDLOG_DEBUG("Total ToD Access Calculation: {}ms", GetPerformanceTimer(PT_TOD_ACCESS).count());
+    SPDLOG_DEBUG("Total Entrance Logic Calculation time: {}ms", GetPerformanceTimer(PT_ENTRANCE_LOGIC).count());
+    SPDLOG_DEBUG("Total Check Logic Calculation time: {}ms", GetPerformanceTimer(PT_LOCATION_LOGIC).count());
     return true;
 }

soh/soh/Enhancements/randomizer/3drando/playthrough.cpp

@@ -11,6 +11,7 @@
 #include "variables.h"
 #include "soh/OTRGlobals.h"
 #include "../option.h"
+#include "../../debugger/performanceTimer.h"
 
 namespace Playthrough {
 
@@ -25,7 +26,9 @@ int Playthrough_Init(uint32_t seed, std::set<RandomizerCheck> excludedLocations,
     ctx->ItemReset();
     ctx->HintReset();
     ctx->GetLogic()->Reset();
+    StartPerformanceTimer(PT_AREA_RESET);
     Areas::AccessReset();
+    StopPerformanceTimer(PT_AREA_RESET);
 
     ctx->GetSettings()->FinalizeSettings(excludedLocations, enabledTricks);
     // once the settings have been finalized turn them into a string for hashing
@@ -71,11 +74,13 @@ int Playthrough_Init(uint32_t seed, std::set<RandomizerCheck> excludedLocations,
         //TODO: Handle different types of file output (i.e. Spoiler Log, Plando Template, Patch Files, Race Files, etc.)
         // write logs
         SPDLOG_INFO("Writing Spoiler Log...");
+        StartPerformanceTimer(PT_SPOILER_LOG);
         if (SpoilerLog_Write()) {
             SPDLOG_INFO("Writing Spoiler Log Done");
         } else {
             SPDLOG_ERROR("Writing Spoiler Log Failed");
         }
+        StopPerformanceTimer(PT_SPOILER_LOG);
 #ifdef ENABLE_DEBUG
         SPDLOG_INFO("Writing Placement Log...");
         if (PlacementLog_Write()) {

soh/soh/Enhancements/randomizer/context.cpp

@@ -1221,4 +1221,5 @@ uint8_t Context::GetAmmo(uint32_t item) {
 void Context::SetAmmo(uint32_t item, uint8_t count) {
     mSaveContext->inventory.ammo[gItemSlots[item]] = count;
 }
+
 } // namespace Rando

soh/soh/Enhancements/randomizer/context.h

@@ -123,6 +123,7 @@ class Context {
     void SetEventChkInf(int32_t flag, bool state);
     uint8_t GetAmmo(uint32_t item);
     void SetAmmo(uint32_t item, uint8_t count);
+    
 
   private:
     static std::weak_ptr<Context> mContext;

soh/soh/Enhancements/randomizer/entrance.cpp

@@ -2,6 +2,7 @@
 
 #include "3drando/pool_functions.hpp"
 #include "3drando/item_pool.hpp"
+#include "../debugger/performanceTimer.h"
 
 #include <spdlog/spdlog.h>
 
@@ -70,21 +71,24 @@ void Entrance::printAgeTimeAccess() {
 }
 
 bool Entrance::ConditionsMet(bool allAgeTimes) const {
+  auto ctx = Rando::Context::GetInstance();
+  StartPerformanceTimer(PT_ENTRANCE_LOGIC);
+  Area* parent = AreaTable(parentRegion);
+  int conditionsMet = 0;
 
-    Area* parent = AreaTable(parentRegion);
+  if (allAgeTimes && !parent->AllAccess()) {
-    int conditionsMet = 0;
+      StopPerformanceTimer(PT_ENTRANCE_LOGIC);
+      return false;
+  }
 
-    if (allAgeTimes && !parent->AllAccess()) {
+  // check all possible day/night condition combinations
-        return false;
+  conditionsMet = (parent->childDay && CheckConditionAtAgeTime(logic->IsChild, logic->AtDay, allAgeTimes)) +
-    }
+                  (parent->childNight && CheckConditionAtAgeTime(logic->IsChild, logic->AtNight, allAgeTimes)) +
+                  (parent->adultDay && CheckConditionAtAgeTime(logic->IsAdult, logic->AtDay, allAgeTimes)) +
+                  (parent->adultNight && CheckConditionAtAgeTime(logic->IsAdult, logic->AtNight, allAgeTimes));
 
-    // check all possible day/night condition combinations
+  StopPerformanceTimer(PT_ENTRANCE_LOGIC);
-    conditionsMet = (parent->childDay && CheckConditionAtAgeTime(logic->IsChild, logic->AtDay, allAgeTimes)) +
+  return conditionsMet && (!allAgeTimes || conditionsMet == 4);
-                    (parent->childNight && CheckConditionAtAgeTime(logic->IsChild, logic->AtNight, allAgeTimes)) +
-                    (parent->adultDay && CheckConditionAtAgeTime(logic->IsAdult, logic->AtDay, allAgeTimes)) +
-                    (parent->adultNight && CheckConditionAtAgeTime(logic->IsAdult, logic->AtNight, allAgeTimes));
-
-    return conditionsMet && (!allAgeTimes || conditionsMet == 4);
 }
 
 uint32_t Entrance::Getuint32_t() const {

soh/soh/Enhancements/randomizer/logic.cpp

@@ -1,4 +1,5 @@
 #include "logic.h"
+#include "../debugger/performanceTimer.h"
 
 #include <algorithm>
 #include <cstdio>
@@ -455,6 +456,7 @@ namespace Rando {
 
     // Updates all logic helpers. Should be called whenever a non-helper is changed
     void Logic::UpdateHelpers() {
+        StartPerformanceTimer(PT_UPDATE_HELPERS);
         OcarinaButtons  =  (HasItem(RG_OCARINA_A_BUTTON) ? 1 : 0) +
                            (HasItem(RG_OCARINA_C_LEFT_BUTTON) ? 1 : 0) +
                            (HasItem(RG_OCARINA_C_RIGHT_BUTTON) ? 1 : 0) +
@@ -659,6 +661,7 @@ namespace Rando {
                             (ctx->GetSettings()->LACSCondition() == RO_LACS_DUNGEONS   && DungeonCount + (Greg && GregInLacsLogic ? 1 : 0) >= ctx->GetOption(RSK_LACS_DUNGEON_COUNT).Value<uint8_t>())                ||
                             (ctx->GetSettings()->LACSCondition() == RO_LACS_TOKENS     && GoldSkulltulaTokens >= ctx->GetOption(RSK_LACS_TOKEN_COUNT).Value<uint8_t>());
         CanCompleteTriforce = TriforcePieces >= ctx->GetOption(RSK_TRIFORCE_HUNT_PIECES_REQUIRED).Value<uint8_t>();
+        StopPerformanceTimer(PT_UPDATE_HELPERS);
     }
 
     bool Logic::SmallKeys(RandomizerRegion dungeon, uint8_t requiredAmount) {
@@ -776,6 +779,7 @@ namespace Rando {
 
     void Logic::Reset() {
         ctx->NewSaveContext();
+        StartPerformanceTimer(PT_LOGIC_RESET);
         memset(inLogic, false, sizeof(inLogic));
         //Settings-dependent variables
         IsKeysanity = ctx->GetOption(RSK_KEYSANITY).Is(RO_DUNGEON_ITEM_LOC_ANYWHERE) || 
@@ -1116,5 +1120,7 @@ namespace Rando {
         LightTrialClearPast      = false;
         BuyDekuShieldPast        = false;
         TimeTravelPast           = false;
+
+        StopPerformanceTimer(PT_LOGIC_RESET);
     }
 }