darrenan
January 18th, 2015, 00:14
I have experienced first-hand, and heard the grumblings from other GMs, about the performance issues in FG (many seconds of 'hang time') when loading an encounter into the combat tracker. Having nothing better to do today, I sat down and created an instrumented version of the main functions that are called when loading the combat tracker: CombatManager.addBattle, CombatManager.addNPCHelper and CombatManager2.addNPC (in the 3.5e ruleset). I am reporting this investigation in the CoreRPG section because the issues I uncovered (described below) are in the CoreRPG ruleset, even though my primary experience of this issue has been via the PFRPG ruleset.
My methodology for performing this analysis was to surround sections of code with the following pattern:
local tSomeOperationBegin = os.clock();
---SomeOperation here---
local tSomeOperationEnd = os.clock();
ChatManager.SystemMessage("SomeOperation elapsed time=" .. tSomeOperationEnd-tSomeOperationBegin);
Using this approach in a slice and dice manner, I was able to quickly isolate the bulk of the execution time as being the two calls to DB.CopyNode in CombatManager.addNPCHelper. I was able to refactor this function to eliminate one of these calls, thus effectively cutting the time to populate the combat tracker in half. I have attached the modified manager_combat.lua for review (note that there is a small section in there still commented-out, it was unclear to me whether those calls would be needed with the code in it's new form).
This is not the whole story though, as I saw some other troubling behavior during the course of this investigation. I expected to be able to add an encounter, clear the combat tracker, and then add the same encounter again and see roughly the same performance both times. I did not see this behavior, however, as every time I populated the encounter the elapsed time to populate the encounter continued to go up, even when clearing the combat tracker in-between. This tells me that somewhere the internal data structures are not being completely cleaned up, either in the LUA ruleset code or the underlying FG libraries. Performing a /reload however, did cause the load times to 'reset', effectively going back to a similar load time each time. What this means is that over the course of a 4-5 hour gaming session we should expect to be continually slowing down from one encounter to the next. I have not yet looked at the CT delete logic, but I plan to next and will post any interesting findings, if any.
I would hope that the devs would also examine the implementation of the DB functions, particularly CopyNode, which seem to be very expensive in terms of time. I'm guessing there are file I/O operations in that code path, and I've heard it said before that FG is essentially single-threaded so it doesn't do anything in the background (which also explains the complete 'hang' when loading the CT). Perhaps the Unity rewrite will enable some level asychronicity in the code?
Also, everyone I've talked to seems to correlate this issue with the number of entries on the NPC's "Spells" tab. Because this tab contains the only extendible portion of the NPC, and causes the size of the NPC to grow, it totally makes sense that NPCs with more entries on their Spells tab take longer to load as this must directly affect the performance of DB.CopyNode. This is unfortunate, as the Spells tab is the primary means for adding NPC capabilities, and will by necessity get larger as the challenge rating (level) of the campaign increases.
Hope this information helps.
D.
My methodology for performing this analysis was to surround sections of code with the following pattern:
local tSomeOperationBegin = os.clock();
---SomeOperation here---
local tSomeOperationEnd = os.clock();
ChatManager.SystemMessage("SomeOperation elapsed time=" .. tSomeOperationEnd-tSomeOperationBegin);
Using this approach in a slice and dice manner, I was able to quickly isolate the bulk of the execution time as being the two calls to DB.CopyNode in CombatManager.addNPCHelper. I was able to refactor this function to eliminate one of these calls, thus effectively cutting the time to populate the combat tracker in half. I have attached the modified manager_combat.lua for review (note that there is a small section in there still commented-out, it was unclear to me whether those calls would be needed with the code in it's new form).
This is not the whole story though, as I saw some other troubling behavior during the course of this investigation. I expected to be able to add an encounter, clear the combat tracker, and then add the same encounter again and see roughly the same performance both times. I did not see this behavior, however, as every time I populated the encounter the elapsed time to populate the encounter continued to go up, even when clearing the combat tracker in-between. This tells me that somewhere the internal data structures are not being completely cleaned up, either in the LUA ruleset code or the underlying FG libraries. Performing a /reload however, did cause the load times to 'reset', effectively going back to a similar load time each time. What this means is that over the course of a 4-5 hour gaming session we should expect to be continually slowing down from one encounter to the next. I have not yet looked at the CT delete logic, but I plan to next and will post any interesting findings, if any.
I would hope that the devs would also examine the implementation of the DB functions, particularly CopyNode, which seem to be very expensive in terms of time. I'm guessing there are file I/O operations in that code path, and I've heard it said before that FG is essentially single-threaded so it doesn't do anything in the background (which also explains the complete 'hang' when loading the CT). Perhaps the Unity rewrite will enable some level asychronicity in the code?
Also, everyone I've talked to seems to correlate this issue with the number of entries on the NPC's "Spells" tab. Because this tab contains the only extendible portion of the NPC, and causes the size of the NPC to grow, it totally makes sense that NPCs with more entries on their Spells tab take longer to load as this must directly affect the performance of DB.CopyNode. This is unfortunate, as the Spells tab is the primary means for adding NPC capabilities, and will by necessity get larger as the challenge rating (level) of the campaign increases.
Hope this information helps.
D.