Impaler[WrG] said:
Perhaps we should look at having some timing data collected durring the tun processing and recorded to a file. We could then load up a saved game under the before and after DLL of any change we make and see what kind of hit were taking on speed.
I belive that these capabilities already exist. There is already profiling data that is either being collected, or the code is set up to just need to set a flag to have it all be collected. I haven't looked at how to use it (those are the PROFILE_FUNC() calls you see at the beginning of each function), although I know right now I'm able to get profiling stats on the init functions at game start, such as the fact that loading the Unit xml file for Civcraft currently takes over 12 seconds on my computer (on a debug build).
Edit
Yup. There's a variable in CvGlobals called m_bDLLProfiler. If that is set to true, then you get profiler output such as below in your logs directory under dllprofile.log. (And BTW, don't use this info as Civ4 info! This is Civcraft which has much of the AI disabled, which would explain the low AI times)
Edit 2:
Oh, here's another thing you might need to know about. It's in FProfiler.h...
Code:
[b]#ifndef FINAL_RELEASE[/b]
#ifndef FP_PROFILE_ENABLE
#define FP_PROFILE_ENABLE
#endif
[b]#endif[/b]
It seems that if you're using a FINAL_RELEASE build, that the profiling might be disabled, even if you set that variable in CvGlobals to true, since the FP_PROFILE_ENABLE definition controls the use of the PROFILE_FUNC definitions. Since I haven't tried it on a final release build, I'm not sure exactly what happens, but if you can't compile a debug build I bet you could just get rid of the emboldened code.
Anyway, this is what I got in my logs by enabling Civcraft's DLL profiling...
Code:
[174376.922] DBG: Total Frame MS: 6542.0 FPS: 000 Min:000 Max:000 Avg:000 SampleFilter:0.010000
Time : Ave : Min% : Max% : Num : Profile Name
-----------------------------------------------------
038.0 : 000.0 : 000.0 : 000.0 : 003 : CvPlayer::doTurn
031.0 : 000.0 : 000.0 : 000.0 : 002 : CvCity::doTurn()
019.0 : 000.3 : 000.1 : 006.8 : 1294 : CvGlobals::getDefineINT
001.0 : 000.0 : 000.0 : 000.0 : 002 : CvCityAI::AI_doTurn
001.0 : 000.0 : 000.0 : 000.0 : 003 : CvCityAI::angryPopulation
011.0 : 000.0 : 000.0 : 000.0 : 002 : CvPlayerAI::AI_unitUpdate
010.0 : 000.0 : 000.0 : 000.0 : 009 : CvSelectionGroupAI::AI_update
004.0 : 000.0 : 000.0 : 000.0 : 005 : CvUnitAI::AI_update
002.0 : 000.0 : 000.0 : 000.0 : 005 : CvSelectionGroup::pushMission
002.0 : 000.0 : 000.0 : 000.0 : 002 : CvPlayer::hasReadyUnit
001.0 : 000.0 : 000.0 : 000.0 : 776 : CvPlot::calculateCulturalOwner()
001.0 : 000.0 : 000.0 : 000.0 : 774 : CvPlot::setOwner
2148.0 : 000.0 : 000.0 : 000.0 : 001 : CvGame::doTurn()
010.0 : 000.0 : 000.0 : 000.0 : 003 : CvTeam::doTurn()
006.0 : 000.0 : 000.0 : 000.0 : 003 : CvTeamAI::AI_updateWorstEnemy
004.0 : 000.1 : 000.0 : 000.1 : 004 : CvPlayerAI::AI_getAttitude
006.0 : 000.1 : 000.0 : 000.1 : 007 : CvPlayerAI::AI_getAttitudeVal
005.0 : 000.1 : 000.0 : 000.1 : 003 : CvPlayerAI::AI_calculateStolenCityRadiusPlots
002.0 : 000.0 : 000.0 : 000.0 : 054 : CvTeamAI::AI_calculateAreaAIType
003.0 : 000.0 : 000.0 : 000.0 : 068 : CvTeam::countNumCitiesByArea
001.0 : 000.0 : 000.0 : 000.0 : 008 : CvTeam::countNumUnitsByArea
001.0 : 000.0 : 000.0 : 000.0 : 001 : CvTeamAI::AI_doWar
042.0 : 000.0 : 000.0 : 000.0 : 001 : CvMap::doTurn()
039.0 : 000.0 : 000.0 : 000.0 : 768 : CvPlot::doTurn
028.0 : 000.0 : 000.0 : 000.0 : 768 : CvPlot::doFeature()
005.0 : 000.0 : 000.0 : 000.0 : 768 : CvPlot::doCulture()
002.0 : 000.0 : 000.0 : 003.6 : 768 : CvPlot::verifyUnitValidPlot
109.0 : 000.0 : 000.0 : 000.0 : 001 : CvPlayer::doTurnUnits
109.0 : 000.0 : 000.0 : 000.0 : 001 : CvPlayerAI::AI_doTurnUnitsPre
108.0 : 000.0 : 000.0 : 000.0 : 001 : CvPlayerAI::AI_updateFoundValues
105.0 : 000.0 : 000.0 : 000.0 : 078 : CvPlayerAI::AI_foundValue()
054.0 : 000.0 : 000.0 : 000.0 : 609 : CvPlayerAI::AI_foundValue() 1
023.0 : 000.4 : 000.4 : 004.2 : 3832 : CvPlot::calculateNatureYield
046.0 : 000.0 : 000.0 : 000.0 : 504 : CvPlayerAI::AI_foundValue() 2
040.0 : 000.0 : 000.0 : 000.0 : 433 : CvPlayerAI::AI_foundValue() 3
001.0 : 000.0 : 000.0 : 000.0 : 065 : CvPlot::isWithinTeamCityRadius
038.0 : 000.0 : 000.0 : 000.0 : 027 : CvPlayerAI::AI_foundValue() 4
038.0 : 000.0 : 000.0 : 000.0 : 027 : CvPlayerAI::AI_bonusVal
002.0 : 000.0 : 000.0 : 000.0 : 171 : CvPlayer::calculateScore
--------------------------------------------------
[174383.734] DBG: Total Frame MS: 2714.0 FPS: 000 Min:000 Max:000 Avg:000 SampleFilter:0.010000
Time : Ave : Min% : Max% : Num : Profile Name
-----------------------------------------------------
028.0 : 001.0 : 000.6 : 001.0 : 003 : CvPlayer::doTurn
020.0 : 000.7 : 000.5 : 000.7 : 002 : CvCity::doTurn()
030.0 : 001.1 : 000.1 : 006.8 : 3468 : CvGlobals::getDefineINT
001.0 : 000.0 : 000.0 : 000.0 : 002 : CvCityAI::AI_doTurn
001.0 : 000.0 : 000.0 : 000.0 : 002 : CvPlot::doImprovement
001.0 : 000.0 : 000.0 : 000.0 : 022 : CvPlayer::canDoCivics
001.0 : 000.0 : 000.0 : 000.0 : 082 : CvPlot::isCoastalLand
445.0 : 016.4 : 001.7 : 016.4 : 003 : CvPlayer::doTurnUnits
342.0 : 012.6 : 001.7 : 012.6 : 003 : CvPlayerAI::AI_doTurnUnitsPre
340.0 : 012.5 : 001.7 : 012.5 : 003 : CvPlayerAI::AI_updateFoundValues
328.0 : 012.1 : 001.6 : 012.1 : 198 : CvPlayerAI::AI_foundValue()
162.0 : 006.0 : 000.8 : 006.0 : 1890 : CvPlayerAI::AI_foundValue() 1
078.0 : 002.9 : 000.4 : 004.2 : 12162 : CvPlot::calculateNatureYield
138.0 : 005.1 : 000.7 : 005.1 : 1680 : CvPlayerAI::AI_foundValue() 2
128.0 : 004.7 : 000.6 : 004.7 : 1493 : CvPlayerAI::AI_foundValue() 3
124.0 : 004.6 : 000.6 : 004.6 : 087 : CvPlayerAI::AI_foundValue() 4
124.0 : 004.6 : 000.6 : 004.6 : 087 : CvPlayerAI::AI_bonusVal
002.0 : 000.1 : 000.0 : 000.1 : 180 : CvTeam::countNumCitiesByArea
002.0 : 000.1 : 000.0 : 000.1 : 166 : CvPlot::isWithinTeamCityRadius
001.0 : 000.0 : 000.0 : 000.0 : 011 : CvSelectionGroup::doTurn()
001.0 : 000.0 : 000.0 : 003.8 : 026 : CvGlobals::getDefineFLOAT
102.0 : 003.8 : 000.0 : 003.8 : 003 : CvPlayerAI::AI_doTurnUnitsPost
001.0 : 000.0 : 000.0 : 000.0 : 009 : CvUnitAI::AI_promote
100.0 : 000.0 : 000.0 : 000.0 : 011 : CvUnitAI::AI_upgrade
007.0 : 000.3 : 000.2 : 000.3 : 002 : CvPlayerAI::AI_unitUpdate
007.0 : 000.3 : 000.2 : 000.3 : 009 : CvSelectionGroupAI::AI_update
004.0 : 000.1 : 000.1 : 000.1 : 005 : CvUnitAI::AI_update
001.0 : 000.0 : 000.0 : 000.0 : 002 : CvPlayer::hasReadyUnit
001.0 : 000.0 : 000.0 : 000.0 : 001 : CvCityAI::AI_doEmphasize
001.0 : 000.0 : 000.0 : 000.0 : 002 : CvPlayerAI::AI_getPlotDanger
002.0 : 000.1 : 000.0 : 000.1 : 774 : CvPlot::setOwner
001.0 : 000.0 : 000.0 : 000.0 : 001 : CvMap::updateFlagSymbols
006.0 : 000.2 : 000.0 : 000.2 : 768 : CvPlot::updateCenterUnit
2240.0 : 082.5 : 032.8 : 082.5 : 001 : CvGame::doTurn()
008.0 : 000.3 : 000.2 : 000.3 : 003 : CvTeam::doTurn()
004.0 : 000.1 : 000.1 : 000.1 : 003 : CvTeamAI::AI_updateWorstEnemy
003.0 : 000.1 : 000.0 : 000.1 : 004 : CvPlayerAI::AI_getAttitude
004.0 : 000.1 : 000.0 : 000.1 : 007 : CvPlayerAI::AI_getAttitudeVal
003.0 : 000.1 : 000.0 : 000.1 : 003 : CvPlayerAI::AI_calculateStolenCityRadiusPlots
001.0 : 000.0 : 000.0 : 000.0 : 054 : CvTeamAI::AI_calculateAreaAIType
002.0 : 000.1 : 000.0 : 000.1 : 001 : CvTeamAI::AI_doWar
028.0 : 001.0 : 000.6 : 001.0 : 001 : CvMap::doTurn()
027.0 : 001.0 : 000.6 : 001.0 : 768 : CvPlot::doTurn
019.0 : 000.7 : 000.4 : 000.7 : 768 : CvPlot::doFeature()
003.0 : 000.1 : 000.1 : 000.1 : 768 : CvPlot::doCulture()
003.0 : 000.1 : 000.0 : 003.6 : 768 : CvPlot::verifyUnitValidPlot
003.0 : 000.1 : 000.0 : 000.1 : 171 : CvPlayer::calculateScore
--------------------------------------------------