1. We have added a Gift Upgrades feature that allows you to gift an account upgrade to another member, just in time for the holiday season. You can see the gift option when going to the Account Upgrades screen, or on any user profile screen.
    Dismiss Notice

Improving game turm time

Discussion in 'Fall Further' started by cde2006, Feb 3, 2009.

  1. cde2006

    cde2006 Chieftain

    Joined:
    Jan 7, 2008
    Messages:
    25
    After playing with the DLL profiler it seems I have found some huge time consuming function:

    Code:
    --------------------------------------------------
    [19956.037] DBG: Total Frame MS: [B]2934.0[/B]  FPS: 000  Min:067 Max:000 Avg:000  SampleFilter:1.010000
     Time   :   Ave  :  Min% :  Max% : Num : Profile Name
    -----------------------------------------------------
    [COLOR="Red"] 2934.0 : 100.0 : 100.0 : 100.0 : 001 :    CvGame::doTurn()[/COLOR]
      030.0 : 001.0 : 000.9 : 002.2 : 218 :       CvPlot::updateSymbols
      002.0 : 000.1 : 000.0 : 000.2 : 218 :          CvPlot::updateSymbolDisplay
      376.0 : 012.8 : 012.8 : 036.0 : 214 :       CvPlot::updateFeatureSymbol
     1682.0 : [B]057.3[/B] : 056.9 : 057.6 : 9174 :       CvPlot::updatePlotGroupBonus
    ...
    Meaning that 57.3% of the Frame time (whatever it is) is spend in 9174 calls to the updatePlotGroupBonus function in my huge map at about turn 407....

    After investigation all calls to updatePlotGroupBonus comes from a single function: changeRevealAllBonuses(-1) at line 1021 of the CvTeam.cpp in the CvTeam::doTurn() function.

    I have created a DLL 050 without the call to changeRevealAllBonuses in CvTeam::doTurn() and basically halved the "Total Frame MS' time:

    After (same turn):

    Code:
    --------------------------------------------------
    [20641.490] DBG: Total Frame MS: [B]1259.0[/B]  FPS: 001  Min:071 Max:000 Avg:001  SampleFilter:1.010000
     Time   :   Ave  :  Min% :  Max% : Num : Profile Name
    -----------------------------------------------------
    [COLOR="Red"] 1259.0 : 100.0 : 099.8 : 100.0 : 001 :    CvGame::doTurn()[/COLOR]
      025.0 : 002.0 : 001.6 : 002.0 : 218 :       CvPlot::updateSymbols
      365.0 : 029.0 : 029.0 : 036.9 : 214 :       CvPlot::updateFeatureSymbol
      016.0 : [B]001.3[/B] : 000.0 : 001.3 : 534 :          CvPlot::updatePlotGroupBonus
      010.0 : 000.8 : 000.8 : 000.9 : 255 :       CvPlayerAI::AI_baseBonusVal
      010.0 : 000.8 : 000.8 : 000.9 : 027 :          CvPlayerAI::AI_baseBonusVal::recalculate
      021.0 : 001.7 : 001.7 : 001.9 : 012 :       CvTeam::doTurn()
    I am not sure what is the use of this function but it doesn't seems to impact my game so far.

    Also the overall game turn time didn't change much for me but I can see more animation going on during AI turn in the optimized version. I will keep investigating to see if I can find some more interesting candidate.

    If you want to activate the profiler, compile the DLL in Release mode (not Final Release) then activate the cheat mode and the logs in the ini .
    In game open the debug menu by "ctrl+shift+alt d" then in Profile check "Show DLL Profile" and "Profile Logging" see attached capture.

    The profile logs are in the dllprofile.log file in your logs folder.
     

    Attached Files:

  2. WarKirby

    WarKirby Arty person

    Joined:
    Jul 13, 2006
    Messages:
    5,317
    Location:
    Glasgow, Scotland
    I'm eaagerly awaiting a response from someone knowledgeable about this.

    Xienwolf, where art thou?
     
  3. Vehem

    Vehem Modmod Monkey

    Joined:
    Nov 22, 2005
    Messages:
    3,219
    Thanks for this - I'd seen the functions for the profiler, but never realized that it provided info is such a useful way. changeRevealAllBonuses sounds related to Dowsing possibly if it is being called every turn (think it normally just gets used for WorldBuilder) - though Xienwolf will know better about that.
     
  4. BeefontheBone

    BeefontheBone Windbag of the sea

    Joined:
    Nov 7, 2005
    Messages:
    2,018
    Sounds like Dowsing to me. Isn't that only really of use to human players anyway?
     
  5. xienwolf

    xienwolf Deity

    Joined:
    Oct 4, 2007
    Messages:
    10,589
    Location:
    Location! Location!
    Yes, it is dowsing, and I can easily fix that by encasing the call in an if (value > 0) check. Normally I do such things, but I apparently did not on here. Though I am not certain why it is being called for every plot on the map (which the large number would indicate to me)


    Thanks for including instructions on how to manage the profiler. I am guessing you use Codeblocks though? I'm not set up so far for a normal Release Mode with VS2008, but I would assume most of it will be fairly intuitive (just the Makefile might be a PITA). Awesome to hear that the CSA+D screen can work properly at all, I wondered why so many functions either did nothing or crashed the game on me.
     
  6. cde2006

    cde2006 Chieftain

    Joined:
    Jan 7, 2008
    Messages:
    25
    Here is my makefile as well as the VS2008 project ^^ (Just remove .txt)

    If you want the profiler in Final Release your can also remove the lines:
    Code:
    #ifndef FINAL_RELEASE
    #ifndef FP_PROFILE_ENABLE 
    	#define FP_PROFILE_ENABLE 
    #endif
    #endif
    and replace with:

    Code:
    #define FP_PROFILE_ENABLE
    
    In FProfiler.h
     

    Attached Files:

  7. cde2006

    cde2006 Chieftain

    Joined:
    Jan 7, 2008
    Messages:
    25
    No, I just used VS2008, which is quite heavy on HD...might give a try to CodeBlocks later whem I am more familiar with the DLL.

    You can profile any function by adding PROFILE() macro at the beginning of the function:
    Code:
    void yourfunction()
    {
    	PROFILE("yourfunction");
    
            /* Your code here */
    }
    One thing I am not sure is how to interpret the first profiler log column. What is the unit? Because if it is milliseconds it's quite short. On my machine the turn 406 take about 20 seconds so where are the 17 missing seconds?
    And if you remember my previous python profiling, the python time was also quite small, so would it be inside the game engine itself that all the time is spend?
    Maybe in graphic update or anything else?
     
  8. xienwolf

    xienwolf Deity

    Joined:
    Oct 4, 2007
    Messages:
    10,589
    Location:
    Location! Location!
    I would guess graphics and/or file access. Maybe also some non-profiled functions. I had wondered what exactly all the PROFILE and FUNC_PROFILE bits were about when I encountered them before.


    Any good reason NOT to enable Profiling in the final release? (Larger file, interrupts gameplay...)?

    And I would advise against switching BACK to codeblocks. VS2008 is most certainly a step better. I think the only thing I miss from Codeblocks was easily adding new files (no Makefile to edit) and the ability to duplicate lines with CTRL+D (but you could only do 1 line at a time, so it wasn't THAT useful). In VS2008 though, I can actually make a debug DLL, and I can retain more than 1 item in the clipboard (CTRL+SHIFT+INSERT)


    I'll probably add profiling to a couple dozen functions of mine which I expect take up exorbient amounts of time. It'd be nice to know that they don't, or at least be able to say for certain that I am willing to accept the time cost.
     
  9. cde2006

    cde2006 Chieftain

    Joined:
    Jan 7, 2008
    Messages:
    25
    Yes, graphics can be easily limited by setting the SetMaxFrameRate to let say 1 or 2 in the ini file :p

    For I/O, I will do some measurement with process explorer or similar tools.

    I will also re-enable the python profiler to see if anything strange.

    It must have some impact, we can measure it if we compare the turn time between profiler enabled in all functions and profiler only enabled in CvGame::doTurn() for example.

    I am not sure this function is the only entry point in the DLL but worth trying.

    Alright, I will play with VS2008 then.

    Do you know if there is any mean to compile the DLL in native VS2008 without passing by the VS2003 toolkit?
    It may also improve the performance as the compiler in VS2008 may generate better binaries. It tried once but the VS2008 DLL refuses to load in the civ executable. I must have missed something. (Like managed and unmanaged DLL and other weirdness from MS...)
     
  10. xienwolf

    xienwolf Deity

    Joined:
    Oct 4, 2007
    Messages:
    10,589
    Location:
    Location! Location!
  11. Opera

    Opera Deity

    Joined:
    Sep 21, 2008
    Messages:
    4,643
    Gender:
    Female
    I tried the .dll. It reduces turn time but it also disables the possibility of creating new units.
    Any idea why?

    Edit: Added savegame. FF050e used.
     

    Attached Files:

  12. Vehem

    Vehem Modmod Monkey

    Joined:
    Nov 22, 2005
    Messages:
    3,219
    The DLL he posted was mostly for reference - I don't know if it was setup to be a usable replacement. In anycase, Xienwolf has fixed the Dowsing code to avoid the slowdown noted (and the method that cde2006 mentioned is going to be very helpful in the future...), so the next patch should be a little quicker...
     
  13. hbar

    hbar Constant

    Joined:
    Feb 6, 2008
    Messages:
    1,307
    Location:
    Wisconsin
    Speaking of the next patch...eta?
     
  14. cde2006

    cde2006 Chieftain

    Joined:
    Jan 7, 2008
    Messages:
    25
    Yes the DLL is not for play as I just simply removed the function call there may be some adverse effect I didn't notice. The purpose was to do some measurement with the profiler.
     

Share This Page