- a few more performance optimizations and logging changes

This commit is contained in:
Mark Vejvoda 2010-09-09 05:42:19 +00:00
parent 77eadd7710
commit d806e7f9ff
4 changed files with 85 additions and 72 deletions

View File

@ -235,7 +235,7 @@ TravelState PathFinder::aStar(Unit *unit, const Vec2i &targetPos){
}
}//while
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, openNodes.empty() = %d, pathFound = %d, nodeLimitReached = %d, unit = %s\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),openNodes.empty(),pathFound,nodeLimitReached,unit->getFullName().c_str());
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, openNodes.empty() = %d, pathFound = %d, nodeLimitReached = %d, unit = %s\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),openNodes.empty(),pathFound,nodeLimitReached,unit->getFullName().c_str());
Node *lastNode= node;
@ -277,7 +277,7 @@ TravelState PathFinder::aStar(Unit *unit, const Vec2i &targetPos){
}
}
//if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 2) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
//clean nodes
openNodes.clear();

View File

@ -1621,7 +1621,7 @@ void Unit::exploreCells() {
game->getWorld()->exploreCells(newPos, sightRange, teamIndex);
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
}
}

View File

@ -109,8 +109,8 @@ void UnitUpdater::updateUnit(Unit *unit) {
}
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [play skill sound]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [play skill sound]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
//start attack particle system
if(unit->getCurrSkill()->getClass() == scAttack) {
@ -121,20 +121,20 @@ void UnitUpdater::updateUnit(Unit *unit) {
}
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [start attack particles]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [start attack particles]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
//update unit
if(unit->update()) {
//SystemFlags::OutputDebug(SystemFlags::debugSystem,"In [%s::%s Line: %d]\n",__FILE__,__FUNCTION__,__LINE__);
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [update unit check]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [update unit check]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
updateUnitCommand(unit);
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [update unit command]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [update unit command]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
//if unit is out of EP, it stops
if(unit->computeEp()) {
@ -142,15 +142,15 @@ void UnitUpdater::updateUnit(Unit *unit) {
unit->cancelCommand();
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [compute ep]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [compute ep]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
//move unit in cells
if(unit->getCurrSkill()->getClass() == scMove) {
world->moveUnitCells(unit);
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [move unit cells]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [move unit cells]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
//play water sound
if(map->getCell(unit->getPos())->getHeight()<map->getWaterLevel() && unit->getCurrField()==fLand){
@ -160,8 +160,8 @@ void UnitUpdater::updateUnit(Unit *unit) {
gameCamera->getPos()
);
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [play water sound]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [play water sound]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
}
}
}
@ -169,8 +169,8 @@ void UnitUpdater::updateUnit(Unit *unit) {
//unit death
if(unit->isDead() && unit->getCurrSkill()->getClass() != scDie) {
unit->kill();
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [kill unit]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [kill unit]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
}
}
@ -188,7 +188,7 @@ void UnitUpdater::updateUnitCommand(Unit *unit){
}
//if no commands stop and add stop command
if(!unit->anyCommand() && unit->isOperative()){
if(unit->anyCommand() == false && unit->isOperative()) {
//SystemFlags::OutputDebug(SystemFlags::debugSystem,"In [%s::%s Line: %d]\n",__FILE__,__FUNCTION__,__LINE__);
unit->setCurrSkill(scStop);
if(unit->getType()->hasCommandClass(ccStop)) {
@ -197,8 +197,7 @@ void UnitUpdater::updateUnitCommand(Unit *unit){
}
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
}
// ==================== updateStop ====================
@ -237,7 +236,6 @@ void UnitUpdater::updateStop(Unit *unit){
}
}
}
//see any unit and cant attack it => run
else if(unit->getType()->hasCommandClass(ccMove)) {
if(attackerOnSight(unit, &sighted)) {
@ -247,8 +245,7 @@ void UnitUpdater::updateStop(Unit *unit){
}
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
}
@ -274,6 +271,9 @@ void UnitUpdater::updateMove(Unit *unit){
throw runtime_error("detected unsupported pathfinder type!");
}
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
switch (tsValue) {
case tsMoving:
unit->setCurrSkill(mct->getMoveSkillType());
@ -290,8 +290,7 @@ void UnitUpdater::updateMove(Unit *unit){
unit->finishCommand();
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
}
@ -314,6 +313,9 @@ void UnitUpdater::updateAttack(Unit *unit){
else {
unit->setCurrSkill(scStop);
}
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
}
else {
//compute target pos
@ -328,6 +330,9 @@ void UnitUpdater::updateAttack(Unit *unit){
pos= command->getPos();
}
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
TravelState tsValue = tsImpossible;
switch(this->game->getGameSettings()->getPathFinderType()) {
case pfBasic:
@ -340,6 +345,9 @@ void UnitUpdater::updateAttack(Unit *unit){
throw runtime_error("detected unsupported pathfinder type!");
}
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
//if unit arrives destPos order has ended
switch (tsValue){
case tsMoving:
@ -355,8 +363,7 @@ void UnitUpdater::updateAttack(Unit *unit){
}
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
}
@ -1468,13 +1475,16 @@ bool UnitUpdater::unitOnRange(const Unit *unit, int range, Unit **rangedPtr,
}
}
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [AFTER LOOP]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 1) chrono.start();
//attack enemies that can attack first
for(int i = 0; i< enemies.size(); ++i) {
if(enemies[i]->getType()->hasSkillClass(scAttack)) {
*rangedPtr= enemies[i];
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, unit %s, range = %d, size = %d, foundInCache = %d, enemies.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),unit->getFullName().c_str(),range,size,foundInCache,enemies.size());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, unit %s, range = %d, size = %d, foundInCache = %d, enemies.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),unit->getFullName().c_str(),range,size,foundInCache,enemies.size());
if(chrono.getMillis() > 1) chrono.start();
return true;
}
@ -1484,14 +1494,13 @@ bool UnitUpdater::unitOnRange(const Unit *unit, int range, Unit **rangedPtr,
if(enemies.size() > 0) {
*rangedPtr= enemies.front();
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, unit %s, range = %d, size = %d, foundInCache = %d, enemies.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),unit->getFullName().c_str(),range,size,foundInCache,enemies.size());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, unit %s, range = %d, size = %d, foundInCache = %d, enemies.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),unit->getFullName().c_str(),range,size,foundInCache,enemies.size());
if(chrono.getMillis() > 1) chrono.start();
return true;
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, unit %s, range = %d, size = %d, foundInCache = %d, enemies.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),unit->getFullName().c_str(),range,size,foundInCache,enemies.size());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld, unit %s, range = %d, size = %d, foundInCache = %d, enemies.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),unit->getFullName().c_str(),range,size,foundInCache,enemies.size());
return false;
}

View File

@ -962,6 +962,7 @@ void World::exploreCells(const Vec2i &newPos, int sightRange, int teamIndex){
ExploredCellsLookupItem::lastDebug = time(NULL);
//printf("In [%s::%s Line: %d] ExploredCellsLookupItemCache.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,ExploredCellsLookupItemCache.size());
SystemFlags::OutputDebug(SystemFlags::debugSystem,"In [%s::%s Line: %d] ExploredCellsLookupItemCache.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,ExploredCellsLookupItemCache.size());
SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] ExploredCellsLookupItemCache.size() = %d\n",__FILE__,__FUNCTION__,__LINE__,ExploredCellsLookupItemCache.size());
}
// Ok we limit the cache size due to possible RAM constraints when
@ -1019,7 +1020,7 @@ void World::exploreCells(const Vec2i &newPos, int sightRange, int teamIndex){
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s] Line: %d took msecs: %lld [CACHE lookup found]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
chrono.start();
return;
}
@ -1027,7 +1028,7 @@ void World::exploreCells(const Vec2i &newPos, int sightRange, int teamIndex){
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [CACHE lookup not found] cacheLookupPosResult = %d, cacheLookupSightResult = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),cacheLookupPosResult,cacheLookupSightResult);
if(chrono.getMillis() > 0) chrono.start();
chrono.start();
Vec2i newSurfPos= Map::toSurfCoords(newPos);
int surfSightRange= sightRange/Map::cellScale+1;
@ -1035,21 +1036,25 @@ void World::exploreCells(const Vec2i &newPos, int sightRange, int teamIndex){
// Explore, this code is quite expensive when we have lots of units
ExploredCellsLookupItem item;
int loopCount = 0;
for(int i = -surfSightRange - indirectSightRange -1; i <= surfSightRange + indirectSightRange +1; ++i) {
for(int j = -surfSightRange - indirectSightRange -1; j <= surfSightRange + indirectSightRange +1; ++j) {
loopCount++;
Vec2i currRelPos= Vec2i(i, j);
Vec2i currPos= newSurfPos + currRelPos;
if(map.isInsideSurface(currPos)){
SurfaceCell *sc= map.getSurfaceCell(currPos);
//explore
if(Vec2i(0).dist(currRelPos) < surfSightRange + indirectSightRange + 1) {
//if(Vec2i(0).dist(currRelPos) < surfSightRange + indirectSightRange + 1) {
if(currRelPos.length() < surfSightRange + indirectSightRange + 1) {
sc->setExplored(teamIndex, true);
item.exploredCellList.push_back(sc);
}
//visible
if(Vec2i(0).dist(currRelPos) < surfSightRange) {
//if(Vec2i(0).dist(currRelPos) < surfSightRange) {
if(currRelPos.length() < surfSightRange) {
sc->setVisible(teamIndex, true);
item.visibleCellList.push_back(sc);
}
@ -1057,8 +1062,8 @@ void World::exploreCells(const Vec2i &newPos, int sightRange, int teamIndex){
}
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [RAW explore cells logic] cacheLookupPosResult = %d, cacheLookupSightResult = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),cacheLookupPosResult,cacheLookupSightResult);
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 1) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [RAW explore cells logic] cacheLookupPosResult = %d, cacheLookupSightResult = %d, loopCount = %d, MaxExploredCellsLookupItemCache = %d\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis(),cacheLookupPosResult,cacheLookupSightResult,loopCount,MaxExploredCellsLookupItemCache);
chrono.start();
// Ok update our caches with the latest info for this position, sight and team
if(MaxExploredCellsLookupItemCache > 0) {
@ -1074,8 +1079,7 @@ void World::exploreCells(const Vec2i &newPos, int sightRange, int teamIndex){
ExploredCellsLookupItemCacheTimer[item.ExploredCellsLookupItemCacheTimerCountIndex] = lookupKey;
}
}
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s] Line: %d took msecs: %lld [add explorecells result to CACHE]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
if(chrono.getMillis() > 0) chrono.start();
if(chrono.getMillis() > 0) SystemFlags::OutputDebug(SystemFlags::debugPerformance,"In [%s::%s Line: %d] took msecs: %lld [add explorecells result to CACHE]\n",__FILE__,__FUNCTION__,__LINE__,chrono.getMillis());
}
//computes the fog of war texture, contained in the minimap