[glob2-devel] profiling

[Luc-Olivier de Charrière]

J'ai essayé de rejouer une fin de parties compilées de 4 manières 
différentes:
C'est une carte de 256x256, avec Moi+1AImorte+1AIvivante, sans fruits, 
sur athlonXp2500+

1)"-g -Wall -pg"
2)"-g -Wall -pg -O3"
3)"-g -O3 -march=athlon-xp -funroll-loops -fprefetch-loop-arrays -pipe"
4)"-O3 -march=athlon-xp -funroll-loops -fprefetch-loop-arrays -pipe"
Pour chaqune de ces compilation, j'ai généré le profile et l'occupation CPU.

Voilà le résimé CPU:

1)
100.0 % | 
************************************************************************
98.5 % | ********
95.0 % | ******
93.5 % | *****
90.0 % | ****
88.5 % | ***
85.0 % | *
83.5 % | *

2)
100.0 % | *****************************************************************
98.5 % | **********
95.0 % | *********
93.5 % | *******
90.0 % | *****
88.5 % | ***
85.0 % | *

3)
100.0 % | *********
98.5 % | *
95.0 % | **
93.5 % | **
90.0 % | **
88.5 % | **
85.0 % | ***
83.5 % | ***
80.0 % | ***
78.5 % | ***
75.0 % | *****
73.5 % | ********
70.0 % | **********
68.5 % | ***********
65.0 % | ***********
63.5 % | **********
60.0 % | ********
58.5 % | ****
55.0 % | **

4)
100.0 % | ***
98.5 % | *
95.0 % | *
93.5 % | *
90.0 % | *
88.5 % | **
85.0 % | **
83.5 % | ***
80.0 % | ***
78.5 % | ***
75.0 % | ****
73.5 % | ********
70.0 % | **********
68.5 % | *************
65.0 % | **************
63.5 % | ************
60.0 % | *********
58.5 % | ******
55.0 % | ***

Et le résumé du profiling:
1)
 %   cumulative   self              self     total          
time   seconds   seconds    calls   s/call   s/call  name   
46.19     70.55    70.55     6589     0.01     0.01  
Map::updateGradient(int, unsigned char, bool, bool)
16.38     95.57    25.02  2912211     0.00     0.00  
SDLDrawableSurface::drawFilledRect(int, int, int, int, unsigned char, 
unsigned char, unsigned char, unsigned char)
 8.59    108.69    13.12      845     0.02     0.02  
Map::updateGlobalGradient(Building*, bool)
 3.92    114.68     5.99      203     0.03     0.04  
Game::renderMiniMap(int, bool)
 2.30    118.20     3.52 65750070     0.00     0.00  
SDLDrawableSurface::drawPixel(int, int, unsigned char, unsigned char, 
unsigned char, unsigned char)
 2.25    121.64     3.44  3408657     0.00     0.00  
SDLSprite::draw(SDL_Surface*, SDL_Rect const*, int, int, int)
 2.21    125.00     3.37 227159511     0.00     0.00  
Map::isRessource(int, int, int)
 1.92    127.94     2.94 113544670     0.00     0.00  
Unit::dxdyfromDirection(int, int*, int*)
 1.83    130.74     2.80 253916481     0.00     0.00  
Map::getRessource(int, int)
 1.81    133.50     2.76  1599997     0.00     0.00  
Map::ressourceAviable(int, int, bool, int, int, int*, int*, int*, 
unsigned char)

2)
 %   cumulative   self              self     total          
time   seconds   seconds    calls   s/call   s/call  name   
46.10     62.14    62.14     6008     0.01     0.01  
Map::updateGradient(int, unsigned char, bool, bool)
17.81     86.15    24.01  2654758     0.00     0.00  
SDLDrawableSurface::drawFilledRect(int, int, int, int, unsigned char, 
unsigned char, unsigned char, unsigned char)
 8.81     98.02    11.87      791     0.02     0.02  
Map::updateGlobalGradient(Building*, bool)
 3.90    103.28     5.26      185     0.03     0.04  
Game::renderMiniMap(int, bool)
 2.95    107.26     3.98 100444522     0.00     0.00  
SDLDrawableSurface::drawPixel(int, int, unsigned char, unsigned char, 
unsigned char, unsigned char)
 2.47    110.58     3.33  3084675     0.00     0.00  
SDLSprite::draw(SDL_Surface*, SDL_Rect const*, int, int, int)
 1.78    112.98     2.40 194432099     0.00     0.00  
Map::isRessource(int, int, int)
 1.78    115.38     2.40 216717600     0.00     0.00  
Map::getRessource(int, int)
 1.19    116.98     1.60 80822501     0.00     0.00  
Unit::dxdyfromDirection(int, int*, int*)
 0.99    118.32     1.34    24873     0.00     0.00  
SDLDrawableSurface::drawCircle(int, int, int, unsigned char, unsigned 
char, unsigned char, unsigned

3)
Each sample counts as 0.01 seconds.
 %   cumulative   self              self     total          
time   seconds   seconds    calls   s/call   s/call  name   
29.65     11.72    11.72     5951     0.00     0.00  
Map::updateGradient(int, unsigned char, bool, bool)
25.30     21.72    10.00  2646247     0.00     0.00  
SDLDrawableSurface::drawFilledRect(int, int, int, int, unsigned char, 
unsigned char, unsigned char, unsigned char)
 7.97     24.87     3.15  3149766     0.00     0.00  
SDLSprite::draw(SDL_Surface*, SDL_Rect const*, int, int, int)
 6.98     27.63     2.76      784     0.00     0.00  
Map::updateGlobalGradient(Building*, bool)
 4.88     29.56     1.93 107437958     0.00     0.00  
SDLDrawableSurface::drawPixel(int, int, unsigned char, unsigned char, 
unsigned char, unsigned char)
 3.85     31.08     1.52  1625453     0.00     0.00  
Map::ressourceAviable(int, int, bool, int, int, int*, int*, int*, 
unsigned char)
 3.49     32.46     1.38   204720     0.00     0.00  
Map::nearestRessource(int, int, int, int*, int*)
 3.24     33.74     1.28      183     0.01     0.01  
Game::renderMiniMap(int, bool)
 2.61     34.77     1.03    27146     0.00     0.00  
SDLDrawableSurface::drawCircle(int, int, int, unsigned char, unsigned 
char, unsigned char, unsigned char)
 1.90     35.52     0.75 154936180     0.00     0.00  
Unit::dxdyfromDirection(int, int*, int*)

4)
 %   cumulative   self              self     total          
time   seconds   seconds    calls   s/call   s/call  name   
24.88      7.16     7.16  2717096     0.00     0.00  
SDLDrawableSurface::drawFilledRect(int, int, int, int, unsigned char, 
unsigned char, unsigned char, unsigned char)
24.53     14.22     7.06     6255     0.00     0.00  
Map::updateGradient(int, unsigned char, bool, bool)
10.42     17.22     3.00  3297767     0.00     0.00  
SDLSprite::draw(SDL_Surface*, SDL_Rect const*, int, int, int)
 6.91     19.21     1.99 102805565     0.00     0.00  
SDLDrawableSurface::drawPixel(int, int, unsigned char, unsigned char, 
unsigned char, unsigned char)
 5.98     20.93     1.72      761     0.00     0.00  
Map::updateGlobalGradient(Building*, bool)
 4.86     22.33     1.40      194     0.01     0.01  
Game::renderMiniMap(int, bool)
 4.03     23.49     1.16    24749     0.00     0.00  
SDLDrawableSurface::drawCircle(int, int, int, unsigned char, unsigned 
char, unsigned char, unsigned char)
 2.33     24.16     0.67   119729     0.00     0.00  
Map::nearestRessource(int, int, int, int*, int*)
 1.91     24.71     0.55     6159     0.00     0.00  Game::drawMap(int, 
int, int, int, int, int, int, bool, bool, bool, bool)
 1.11     25.03     0.32   723569     0.00     0.00  
Map::ressourceAviable(int, int, bool, int, int, int*, int*, int*, 
unsigned char)


Pour optimiser la vitesse, il est interessant de savoir que:

1-"Map::updateGradient(int, unsigned char, bool, bool)" a un temps 
d'execution fixe.
Elle est appelée à chaque step() (40ms), pour mettre à jour le gradient 
d'une ressource pour un joueur, pour ceux qui nage ou ceux qui ne nagent 
pas.

2-"Map::updateGlobalGradient(Building*, bool)" prends plus de temps que 
"Map::updateGradient(int, unsigned char, bool, bool)".
Par exemple, sur ce PC(avec -O3), j'ai le temps de l'appeler *une* fois 
par step(), sinon le CPU est surchargé (pour le step() est question).
Donc, j'ai *tout* fait pour éviter son appel.
Mais surtout, si "Map::updateGradient(int, unsigned char, bool, bool)" 
prends une proportion du CPU trop importante (>70%),
alors le jeu va souvent bloquer (une image prendra peut-être 60ms au 
lieu de 40 un peu souvent).

3-les méthodes "updateGradient()" consomment un temps proportionnels à 
la surface de la carte.


Mon analyse:

-Les affichages graphiques prennent énormément de temps, on le pensait 
deja, maintenant on en est sûr. Si SDL supporte la sortie openGL, on 
gagnera 10% à 30% ?

-L'optimisation "-O3" ne fait pas grand chose en comparaison avec 
"-march=athlonxp". Quels processeurs n'ont pas de "-march="?
Si il y en a, ils sont un peu mal. Enfin, surtout limité à des cartes 
128x128.
Ou alors il faut voire si on ne peut pas encore optimiser...comme ça je 
ne voit pas, faudrait une bonne idée mathématique!
Si ça interese quelqun, je lui explique volontier.

-Ca veut aussi dire que on risque d'avoir un glob2 pas utilisable sur 
des petit processeurs.

-Pour les autres, c'est cool, "-march=" est *méga* efficace dans les 
méthodes de gradient.

-Je peut bosser sur les méthodes d'updateGradient(), et que j'ai assez 
bossé les moyens de les éviter!

-Il faut essayer une partie complète pour en savoir plus.