Incompréhension du temps d'execution

Version imprimable

Hello,

Je reprend un ancien projet : création d'une image (chargement d'une font et bin paking pour en faire un atlas), puis création d'un SDF à partir de cet atlas.

Mon but est de réduire le temps d'exec, plus par curiosité que par nécessité.

Et là je me retrouve face à un truc bizarre : afficher l'image générée multiplie par 3 son temps de création :aie:.

Mon code ressemble à ça:

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
template <class Function>
void timeIt(Function function, std::string const& desc) {
	auto startTime = std::chrono::high_resolution_clock::now();
	function();	
	auto endTime = std::chrono::high_resolution_clock::now();
	auto t = std::chrono::duration_cast<std::chrono::duration<double>>(endTime - startTime);
	std::cout << desc << t.count() << " seconds." << std::endl;
}
 
int main(int, char**) {
	sf::Image atlas;
	timeIt([&]() {
		pack(atlas, "sansation_bold.ttf", 600, 32, 4096);
	}, "Atlas generated in ");
	atlas.saveToFile("atlas.png");
 
	sf::Image resultImage;	
	timeIt([&]() {
		generateSDFFrom4ChannelsMT(resultImage,
				"atlas.png",
				"atlas.png",
				"atlas.png",
				"atlas.png",
				256, 256,
				centeredLinearDistance(128.)); },
		"SDF generated in ");
	resultImage.saveToFile("atlas_4.png");
	return 0;
}

Qui me donne

Code:

1
2
Atlas generated in 0.813719 seconds.
SDF generated in 2.43448 seconds.

(Même temps d'exec en autorisant le compilo à générer du code SSE2 ou AVX).

Maintenant en changeant le code pour devenir

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
template <class Function>
void timeIt(Function function, std::string const& desc) {
	auto startTime = std::chrono::high_resolution_clock::now();
	function();	
	auto endTime = std::chrono::high_resolution_clock::now();
	auto t = std::chrono::duration_cast<std::chrono::duration<double>>(endTime - startTime);
	std::cout << desc << t.count() << " seconds." << std::endl;
}
 
int main(int, char**) {
	sf::Image atlas;
	timeIt([&]() {
		pack(atlas, "sansation_bold.ttf", 600, 32, 4096);
	}, "Atlas generated in ");
	atlas.saveToFile("atlas.png");
 
	sf::Image resultImage;	
	timeIt([&]() {
		generateSDFFrom4ChannelsMT(resultImage,
				"atlas.png",
				"atlas.png",
				"atlas.png",
				"atlas.png",
				256, 256,
				centeredLinearDistance(128.)); },
		"SDF generated in ");
	resultImage.saveToFile("atlas_4.png");
 
	// boucle d'affichage
 
	return 0;
}

Le temps d'exec reste le même avec du code SSE2 (logique), mais est triplé avec du code AVX (atlas : 0.8sec / SDF : 7.3sec).

Comment est-ce possible que la boucle d'affichage impacte le temps de création du SDF ? :aie:

09/12/2015, 11h33
dragonjoker59

On va dire que tout dépend de ce que la boucle d'affichage fait.
Peut être qu'avec celle-ci le compilo ne génère tout simplement pas de code AVX.
09/12/2015, 22h00
koala01
Salut,

Une question sans doute idiote : ne t'amuserais tu pas, tout bêtement, à charger en mémoire quatre fois le même fichier png là où un seul chargement devrait pouvoir suffire (vu que tu donnes chaque fois le même nom de fichier) :question:

N'aurais tu pas intérêt-- ce n'est qu'une supposition, ne sachant pas ce que fait exactement generateSDFFrom4ChannelsMT -- à repérer les cas où plusieurs fichiers sont identiques afin ne le charger qu'une seule fois et d'utiliser une copie (enfin, un clone plutôt) de la ressource obtenue après extraction pour les différentes étapes à effectuer :question:

Parce que, si j'ai bien compris (reprends moi si je dis une connerie, je ne m'offusquerai pas ;) ) ta fonction generateSDFFrom4ChannelsMT va travailler sous une forme qui pourrait être proche de:
1. charger le fichier 1
2. charger le fichier 2
3. charger le fichier 3
4. charger le fichier 4
5. (éventuellement) appliquer des transformations spécifiques pour
  - la "texture" obtenue depuis le fichier1
  - la "texture" obtenue depuis le fichier2
  - la "texture" obtenue depuis le fichier3
  - la "texture" obtenue depuis le fichier4
6. calculer le résultat de la combinaison de quatre textures
Or, l'extraction des données d'un fichier png est -- certes-- relativement facile, il n'en demeure pas moins que... c'est un processus qui prend du temps.

Cela vaudrait surement la peine d'effectuer un benchmark pour valider mon hypothèse, mais j'ai l'impression que c'est à ce niveau que tout se joue ;)
10/12/2015, 07h40
Iradrille

@dragonjoker59, la boucle d'affichage est totalement indépendante, ça ne devrais pas gêner.

@koala01, c'est exactement ça, charger 4 images, travailler sur les 4, puis calculer un résultat à partir des 4. Ici les 4 sont les mêmes (ça mériterait effectivement un cas particulier ;)), mais ce n'est pas toujours le cas.
Mais les calculs sont fait 4 fois qu'on affiche le résultat ou pas. Ce qui est bizarre c'est qu'en affichant le résultat le temps d'exec est multiplié par 3.

Citation:

Envoyé par dragonjoker59

On va dire que tout dépend de ce que la boucle d'affichage fait.
Peut être qu'avec celle-ci le compilo ne génère tout simplement pas de code AVX.

Après vérification (diff du binaire généré) : aucune différence ici.
A part des offsets différents, la seule différence est au niveau de la boucle d'affichage (présente d'un coté et non de l'autre).

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
Comparaison des fichiers NO_DISPLAY.TXT et WITH_DISPLAY.TXT
...
***** NO_DISPLAY.TXT
main    PROC                                            
$LN138:
        push    rbp
        lea     rbp, QWORD PTR [rsp-87]
        sub     rsp, 144                                
        mov     QWORD PTR $T31[rbp-57], -2
        mov     QWORD PTR [rsp+160], rbx
        mov     rax, QWORD PTR __security_cookie
***** WITH_DISPLAY.TXT
main    PROC                                            
$LN202:
        push    rbp
        lea     rbp, QWORD PTR [rsp-1040]
        sub     rsp, 1296                               
        mov     QWORD PTR $T36[rsp], -2
        mov     QWORD PTR [rsp+1312], rbx
        mov     rax, QWORD PTR __security_cookie
*****
...