Différence de performances dans l'appel d'une fonction virtuelle

Version imprimable

Bonsoir

Je n'arrive pas à m'expliquer la différence de temps d'exécution entre l'appel direct d'une méthode virtuelle sur une classe et l'appel délégué de cette même méthode virtuelle à partir d'une autre classe

pour information, je suis sous gcc 4.5.1 (g++ -std=c++0x -O2)
sous Ubuntu 10.04

le code :

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
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
 
#include <iostream>
#include <string>
#include <memory>
#include <chrono>
#include <vector>
using namespace std;
 
class Print{
 
public:
 
virtual void print(int p1, float p2, float p3, float p4){}
 
};
 
class PrintWrapper
{
 
    public:
 
      PrintWrapper(shared_ptr<Print> print, int p1, float p2, float p3, float p4) :
      m_print(print), _p1(p1),_p2(p2),_p3(p3),_p4(p4){}
 
      ~PrintWrapper(){}
 
      void execute()
      { 
        m_print->print(_p1,_p2,_p3,_p4); 
      }
 
    private:
 
      shared_ptr<Print> m_print;
      int _p1;
      float _p2,_p3,_p4;
 
};
 
void test()
{
 shared_ptr<Print> p(new Print());
 shared_ptr<PrintWrapper> pw(new PrintWrapper(p, 1, 2.f,3.0f,4.0f));
 
 //-------------test 1-------------------------
 auto time1 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < 1000000; ++var) 
 {
   p->print(1, 2.f,3.0f,4.0f);
 }
 
 auto time2 = std::chrono::system_clock::now();
 
 cout <<"test 1 : "<< (time2 - time1).count() << " microseconds." << endl;
 
  //-------------test 2-------------------------
 auto time3 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < 1000000; ++var) 
 {
   pw->execute();
 }
 
 auto time4 = std::chrono::system_clock::now();
 
 cout <<"test 2 : "<< (time4 - time3).count() << " microseconds." << endl;
 
}
int main() { test(); }

verdict :

test 1 : 3494 microseconds.
test 2 : 5888 microseconds.

soit plus de 60% de différence ! comment l'expliquer ? bien sûr print ne fait rien mais quand même...

dans le doute j'ai testé également avec ideone (même niveau d'optimisation) :

http://ideone.com/p3hjp

même résultats

05/12/2011, 02h58
Flob90

Tu fais trop peu d'itérations pour que ce soit pertinant (lances le test plusieurs fois, tu verras les résultats varier), passes à 1 000 000 000 itérations. Personnelement j'obtients une différence de quelques % (5% environ).
05/12/2011, 16h44
coda_blank

Citation:

Envoyé par Flob90

Tu fais trop peu d'itérations pour que ce soit pertinant (lances le test plusieurs fois, tu verras les résultats varier), passes à 1 000 000 000 itérations. Personnelement j'obtients une différence de quelques % (5% environ).

je ne sais pas comment tu t'y est pris chez toi mais je viens de refaire le test avec 100 000 000 itérations sur ideone (au delà le temps d’exécution max est dépassé) et le rapport n'a pas changé :

test 1 : 350116 microseconds.
test 2 : 589507 microseconds.

c'est quand même embêtant cette histoire, si même le simple fait d’appeler une méthode virtuelle depuis une classe engendre un overhead, je n'ose pas imaginer ce que cela donne quand on a une dizaine d'appels virtuels imbriqués
05/12/2011, 17h35
Flob90

J'ai testé en -O2 (ca marche même en -O1), ideone ne doit pas compiler en optimisé. Refais le test sur ta propre machine.
05/12/2011, 18h16
Luc Hermitte

Il y a un niveau d'indirection supplémentaire. C'est ça que tu mesures.

~~Les compteurs (et en particulier les atomiques), ce n'est pas gratuit.~~ (EDIT: mais pas applicable ici ; c'est plutôt l'indirection qui rajoute une assertion qui est mesurée)
05/12/2011, 21h35
coda_blank

Citation:

Envoyé par Flob90

J'ai testé en -O2 (ca marche même en -O1), ideone ne doit pas compiler en optimisé. Refais le test sur ta propre machine.

j'ai refait le test avec toutes les optimisations possibles et j'aboutis au même résultat

je veux juste savoir si c'est qqchose de normal
05/12/2011, 21h37
coda_blank

Citation:

Envoyé par Luc Hermitte

Il y a un niveau d'indirection supplémentaire. C'est ça que tu mesures.
Les compteurs (et en particulier les atomiques), ce n'est pas gratuit.

ou ça ? dans chacun des tests j’appelle la méthode virtuelle, sauf que dans le deuxième je le fait à partir de méthode (non virtuelle) d'une classe

aucun niveau d'indirection supplémentaire là-dedans

Salut,
souvent compilateur varie ...

j'ai rajouté une boucle dans ton main pour répéter 10x l'appel à test et j'ai changé la constante à 100 000 000.

Visual C++ (- /O2 /Ot):

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
test 1 : 3930000 microseconds.
test 2 : 3440000 microseconds.
 
test 1 : 3870000 microseconds.
test 2 : 3460000 microseconds.
 
test 1 : 4850000 microseconds.
test 2 : 3910000 microseconds.
 
test 1 : 4550000 microseconds.
test 2 : 4210000 microseconds.
 
test 1 : 4530000 microseconds.
test 2 : 3430000 microseconds.
 
test 1 : 3820000 microseconds.
test 2 : 3390000 microseconds.
 
test 1 : 3860000 microseconds.
test 2 : 3400000 microseconds.
 
test 1 : 3820000 microseconds.
test 2 : 3390000 microseconds.
 
test 1 : 3860000 microseconds.
test 2 : 3390000 microseconds.
 
test 1 : 3830000 microseconds.
test 2 : 3400000 microseconds.
 
Appuyez sur une touche pour continuer...

MinGW (gcc 4.6.1) (-fexpensive-optimizations -O2)

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
33
test 1 : 442000 microseconds.
test 2 : 567000 microseconds.
 
test 1 : 438000 microseconds.
test 2 : 581000 microseconds.
 
test 1 : 561000 microseconds.
test 2 : 727000 microseconds.
 
test 1 : 439000 microseconds.
test 2 : 556000 microseconds.
 
test 1 : 437000 microseconds.
test 2 : 556000 microseconds.
 
test 1 : 428000 microseconds.
test 2 : 556000 microseconds.
 
test 1 : 432000 microseconds.
test 2 : 557000 microseconds.
 
test 1 : 434000 microseconds.
test 2 : 556000 microseconds.
 
test 1 : 428000 microseconds.
test 2 : 553000 microseconds.
 
test 1 : 427000 microseconds.
test 2 : 557000 microseconds.
 
 
Process returned 0 (0x0)   execution time : 10.309 s
Press any key to continue.

Difficile de tirer une conclusion...

06/12/2011, 08h48
Flob90

Bha oui :
Cas 1 : p -> operator-> -> print
Cas 2 : p -> operator-> -> execute -> operator-> -> print

Tu as toujours +60% avec gcc en O3 et 1000000000 sur ta propre machine ? Si c'est le cas c'est vraiment étrange ...

@3DArchi: Une conclusion franche peut-être pas, mais on voit que t'es quand même pas à une différence de 60%.
06/12/2011, 08h51
3DArchi

Citation:

Envoyé par Flob90

@3DArchi: Une conclusion franche peut-être pas, mais on voit que t'es quand même pas à une différence de 60%.

C'est surtout que j'ai les résultats relativement inverses entre visual et gcc. Avec visual, le second cas est toujours un peu mieux performant que le premier. Exactement l'inverse avec Mingw.
06/12/2011, 11h58
Luc Hermitte

Citation:

Envoyé par coda_blank

ou ça ? dans chacun des tests j’appelle la méthode virtuelle, sauf que dans le deuxième je le fait à partir de méthode (non virtuelle) d'une classe

aucun niveau d'indirection supplémentaire là-dedans

Citation:

Envoyé par Flob90

Bha oui :
Cas 1 : p -> operator-> -> print
Cas 2 : p -> operator-> -> execute -> operator-> -> print

L'opérateur -> des shared_ptr réalise donc un déréférencement, et aussi un test de non nullité -- qui est derrière un BOOST_ASSERT.

Pour la différence de perf entre VC et mingw, regardez à tout hasard comment est implémenté le shared_ptr dans les deux cas.

Sinon, il reste toujours la comparaison des codes assembleurs produits. Et n'oubliez pas de neutraliser l'assertion...
06/12/2011, 14h21
koala01

Salut,

Pour rebondir sur la dernière réaction de luc:

@coda_blank As tu bien vérifié que tu compilais en mode release et non en mode debug :question:

Je ne serais pas étonné outre mesure que tu travailles en mode débug pour faire ton test et que, du coup, il y ait tout le code correspondant aux assertions qui soit effectué ;)

bon 'ai simplifié le code en enlevant le shared_ptr, (ce qui n'a rien changé au constat initial), j'ai mis en commentaire les mesures du temps, je n'ai gardé que le strict nécessaire

test.cpp

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
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
#include <iostream>
#include <string>
#include <memory>
#include <chrono>
#include <vector>
using namespace std;
 
#define ITER 100000000
 
class Print{
 
public:
 
//typedef shared_ptr<Print> Ptr;
typedef Print* Ptr;
 
virtual void print(int p1, float p2, float p3, float p4){/*print */}
 
};
 
class PrintWrapper
{
 
    public:
 
      //typedef shared_ptr<PrintWrapper> Ptr;
      typedef PrintWrapper* Ptr;
 
      PrintWrapper(Print::Ptr print, int p1, float p2, float p3, float p4) :
      m_print(print), _p1(p1),_p2(p2),_p3(p3),_p4(p4){}
 
      ~PrintWrapper(){}
 
      void execute()
      { 
        m_print->print(_p1,_p2,_p3,_p4); 
      }
 
    private:
 
      Print::Ptr m_print;
      int _p1;
      float _p2,_p3,_p4;
 
};
 
 //Print::Ptr p(new Print());
 //PrintWrapper::Ptr pw(new PrintWrapper(p, 1, 2.f,3.0f,4.0f));
 Print::Ptr p = new Print();
 PrintWrapper::Ptr pw = new PrintWrapper(p, 1, 2.f,3.0f,4.0f);
 
void test1()
{
 
 //-------------test 1-------------------------
 //auto time1 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
 {
   p->print(1, 2.f,3.0f,4.0f);
 }
 
 //auto time2 = std::chrono::system_clock::now();
 
 //cout <<"test 1 : "<< (time2 - time1).count() << " microseconds." << endl;
 
 }
 
 void test2()
 {
 
 
  //-------------test 2-------------------------
 //auto time3 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
 {
   pw->execute();
 }
 
 //auto time4 = std::chrono::system_clock::now();
 
 //cout <<"test 2 : "<< (time4 - time3).count() << " microseconds." << endl;
 
}
int main() { test1(); test2();}

ensuite j'ai fait un profiling avec gprof et objdump (pour le code assembleur)

les résultats de gprof sont dans gprof.output et ceux de objdump sont dans objdump.txt

tout est clair ? :)

le makefile :

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
GCC = g++
COMPILE_FLAGS = -std=c++0x -pg -g -O2
LINK_FLAGS = -pg
 
test:	test.o
	$(GCC) $(LINK_FLAGS) test.o -o $@
 
test.o:	test.cpp
	$(GCC) -c $(COMPILE_FLAGS) $<
 
objdump : test.o
	objdump -d -M intel -S test.o > objdump.txt
 
exec : 	test
	./test
 
gprof : exec
	exec
	gprof test > gprof.output
 
clean:
	rm -f *.o *.output test gmon.out objdump.txt
 
all : 	clean objdump gprof

dans gprof.output on observe sans ambiguité que test2 prend plus de temps que test1 :

Code:

1
2
3
4
5
6
 
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 43.18      0.19     0.19 200000000     0.00     0.00  Print::print(int, float, float, float)
 36.36      0.35     0.16        1   160.00   255.00  test2()
 20.45      0.44     0.09        1    90.00   185.00  test1()

mais pour ce qui est du code asm, je suis loin d'être un expert :(, si ce n'est que l'appel à print prend 6 mov dans test1 contre 11 dans test2 :

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
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
test.o:     file format elf32-i386
 
 
Disassembly of section .text:
 
00000000 <_Z5test1v>:
 //PrintWrapper::Ptr pw(new PrintWrapper(p, 1, 2.f,3.0f,4.0f));
 Print::Ptr p = new Print();
 PrintWrapper::Ptr pw = new PrintWrapper(p, 1, 2.f,3.0f,4.0f);
 
void test1()
{
   0:	55                   	push   ebp
   1:	89 e5                	mov    ebp,esp
   3:	53                   	push   ebx
   4:	83 ec 24             	sub    esp,0x24
   7:	e8 fc ff ff ff       	call   8 <_Z5test1v+0x8>
 
 //-------------test 1-------------------------
 //auto time1 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
   c:	31 db                	xor    ebx,ebx
   e:	66 90                	xchg   ax,ax
 {
   p->print(1, 2.f,3.0f,4.0f);
  10:	a1 00 00 00 00       	mov    eax,ds:0x0
{
 
 //-------------test 1-------------------------
 //auto time1 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
  15:	83 c3 01             	add    ebx,0x1
 {
   p->print(1, 2.f,3.0f,4.0f);
  18:	8b 10                	mov    edx,DWORD PTR [eax]
  1a:	c7 44 24 10 00 00 80 	mov    DWORD PTR [esp+0x10],0x40800000
  21:	40 
  22:	c7 44 24 0c 00 00 40 	mov    DWORD PTR [esp+0xc],0x40400000
  29:	40 
  2a:	c7 44 24 08 00 00 00 	mov    DWORD PTR [esp+0x8],0x40000000
  31:	40 
  32:	c7 44 24 04 01 00 00 	mov    DWORD PTR [esp+0x4],0x1
  39:	00 
  3a:	89 04 24             	mov    DWORD PTR [esp],eax
  3d:	ff 12                	call   DWORD PTR [edx]
{
 
 //-------------test 1-------------------------
 //auto time1 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
  3f:	81 fb 00 e1 f5 05    	cmp    ebx,0x5f5e100
  45:	75 c9                	jne    10 <_Z5test1v+0x10>
 
 //auto time2 = std::chrono::system_clock::now();
 
 //cout <<"test 1 : "<< (time2 - time1).count() << " microseconds." << endl;
 
 }
  47:	83 c4 24             	add    esp,0x24
  4a:	5b                   	pop    ebx
  4b:	5d                   	pop    ebp
  4c:	c3                   	ret    
  4d:	8d 76 00             	lea    esi,[esi+0x0]
 
00000050 <_Z5test2v>:
 
 void test2()
 {
  50:	55                   	push   ebp
  51:	89 e5                	mov    ebp,esp
  53:	56                   	push   esi
  54:	53                   	push   ebx
  55:	83 ec 20             	sub    esp,0x20
  58:	e8 fc ff ff ff       	call   59 <_Z5test2v+0x9>
 
 
  //-------------test 2-------------------------
 //auto time3 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
  5d:	31 db                	xor    ebx,ebx
  5f:	90                   	nop
 {
   pw->execute();
  60:	a1 00 00 00 00       	mov    eax,ds:0x0
 
 
  //-------------test 2-------------------------
 //auto time3 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
  65:	83 c3 01             	add    ebx,0x1
 
      ~PrintWrapper(){}
 
      void execute()
      { 
        m_print->print(_p1,_p2,_p3,_p4); 
  68:	8b 10                	mov    edx,DWORD PTR [eax]
  6a:	8b 70 10             	mov    esi,DWORD PTR [eax+0x10]
  6d:	8b 0a                	mov    ecx,DWORD PTR [edx]
  6f:	89 74 24 10          	mov    DWORD PTR [esp+0x10],esi
  73:	8b 70 0c             	mov    esi,DWORD PTR [eax+0xc]
  76:	89 74 24 0c          	mov    DWORD PTR [esp+0xc],esi
  7a:	8b 70 08             	mov    esi,DWORD PTR [eax+0x8]
  7d:	89 74 24 08          	mov    DWORD PTR [esp+0x8],esi
  81:	8b 40 04             	mov    eax,DWORD PTR [eax+0x4]
  84:	89 14 24             	mov    DWORD PTR [esp],edx
  87:	89 44 24 04          	mov    DWORD PTR [esp+0x4],eax
  8b:	ff 11                	call   DWORD PTR [ecx]
 
 
  //-------------test 2-------------------------
 //auto time3 = std::chrono::system_clock::now();
 
 for (auto var = 0; var < ITER; ++var) 
  8d:	81 fb 00 e1 f5 05    	cmp    ebx,0x5f5e100
  93:	75 cb                	jne    60 <_Z5test2v+0x10>
 
 //auto time4 = std::chrono::system_clock::now();
 
 //cout <<"test 2 : "<< (time4 - time3).count() << " microseconds." << endl;
 
}
  95:	83 c4 20             	add    esp,0x20
  98:	5b                   	pop    ebx
  99:	5e                   	pop    esi
  9a:	5d                   	pop    ebp
  9b:	c3                   	ret    
  9c:	8d 74 26 00          	lea    esi,[esi+eiz*1+0x0]
 
000000a0 <main>:
int main() { test1(); test2();}
  a0:	55                   	push   ebp
  a1:	89 e5                	mov    ebp,esp
  a3:	83 e4 f0             	and    esp,0xfffffff0
  a6:	e8 fc ff ff ff       	call   a7 <main+0x7>
  ab:	e8 fc ff ff ff       	call   ac <main+0xc>
  b0:	e8 fc ff ff ff       	call   b1 <main+0x11>
  b5:	31 c0                	xor    eax,eax
  b7:	89 ec                	mov    esp,ebp
  b9:	5d                   	pop    ebp
  ba:	c3                   	ret    
  bb:	90                   	nop
  bc:	8d 74 26 00          	lea    esi,[esi+eiz*1+0x0]
 
000000c0 <_GLOBAL__I_p>:
  c0:	55                   	push   ebp
  c1:	89 e5                	mov    ebp,esp
  c3:	83 ec 18             	sub    esp,0x18
  c6:	e8 fc ff ff ff       	call   c7 <_GLOBAL__I_p+0x7>
  extern wostream wclog;	///< Linked to standard error (buffered)
#endif
  //@}
 
  // For construction of filebuffers for cout, cin, cerr, clog et. al.
  static ios_base::Init __ioinit;
  cb:	c7 04 24 08 00 00 00 	mov    DWORD PTR [esp],0x8
  d2:	e8 fc ff ff ff       	call   d3 <_GLOBAL__I_p+0x13>
  d7:	c7 44 24 08 00 00 00 	mov    DWORD PTR [esp+0x8],0x0
  de:	00 
  df:	c7 44 24 04 08 00 00 	mov    DWORD PTR [esp+0x4],0x8
  e6:	00 
  e7:	c7 04 24 00 00 00 00 	mov    DWORD PTR [esp],0x0
  ee:	e8 fc ff ff ff       	call   ef <_GLOBAL__I_p+0x2f>
 
};
 
 //Print::Ptr p(new Print());
 //PrintWrapper::Ptr pw(new PrintWrapper(p, 1, 2.f,3.0f,4.0f));
 Print::Ptr p = new Print();
  f3:	c7 04 24 04 00 00 00 	mov    DWORD PTR [esp],0x4
  fa:	e8 fc ff ff ff       	call   fb <_GLOBAL__I_p+0x3b>
#include <vector>
using namespace std;
 
#define ITER 100000000
 
class Print{
  ff:	c7 00 08 00 00 00    	mov    DWORD PTR [eax],0x8
};
 
 //Print::Ptr p(new Print());
 //PrintWrapper::Ptr pw(new PrintWrapper(p, 1, 2.f,3.0f,4.0f));
 Print::Ptr p = new Print();
 PrintWrapper::Ptr pw = new PrintWrapper(p, 1, 2.f,3.0f,4.0f);
 105:	c7 04 24 14 00 00 00 	mov    DWORD PTR [esp],0x14
 
};
 
 //Print::Ptr p(new Print());
 //PrintWrapper::Ptr pw(new PrintWrapper(p, 1, 2.f,3.0f,4.0f));
 Print::Ptr p = new Print();
 10c:	a3 00 00 00 00       	mov    ds:0x0,eax
 PrintWrapper::Ptr pw = new PrintWrapper(p, 1, 2.f,3.0f,4.0f);
 111:	e8 fc ff ff ff       	call   112 <_GLOBAL__I_p+0x52>
 
      //typedef shared_ptr<PrintWrapper> Ptr;
      typedef PrintWrapper* Ptr;
 
      PrintWrapper(Print::Ptr print, int p1, float p2, float p3, float p4) :
      m_print(print), _p1(p1),_p2(p2),_p3(p3),_p4(p4){}
 116:	8b 15 00 00 00 00    	mov    edx,DWORD PTR ds:0x0
 11c:	c7 40 04 01 00 00 00 	mov    DWORD PTR [eax+0x4],0x1
 123:	89 10                	mov    DWORD PTR [eax],edx
 125:	c7 40 08 00 00 00 40 	mov    DWORD PTR [eax+0x8],0x40000000
 12c:	c7 40 0c 00 00 40 40 	mov    DWORD PTR [eax+0xc],0x40400000
 133:	c7 40 10 00 00 80 40 	mov    DWORD PTR [eax+0x10],0x40800000
};
 
 //Print::Ptr p(new Print());
 //PrintWrapper::Ptr pw(new PrintWrapper(p, 1, 2.f,3.0f,4.0f));
 Print::Ptr p = new Print();
 PrintWrapper::Ptr pw = new PrintWrapper(p, 1, 2.f,3.0f,4.0f);
 13a:	a3 00 00 00 00       	mov    ds:0x0,eax
 //auto time4 = std::chrono::system_clock::now();
 
 //cout <<"test 2 : "<< (time4 - time3).count() << " microseconds." << endl;
 
}
int main() { test1(); test2();}
 13f:	c9                   	leave  
 140:	c3                   	ret    
 
Disassembly of section .text._ZN5Print5printEifff:
 
00000000 <_ZN5Print5printEifff>:
public:
 
//typedef shared_ptr<Print> Ptr;
typedef Print* Ptr;
 
virtual void print(int p1, float p2, float p3, float p4){/*print */}
   0:	55                   	push   ebp
   1:	89 e5                	mov    ebp,esp
   3:	e8 fc ff ff ff       	call   4 <_ZN5Print5printEifff+0x4>
   8:	5d                   	pop    ebp
   9:	c3                   	ret

voilà :P

06/12/2011, 19h54
Joel F

ca fait 45 siecles que les processeurs sont pipelinés. Regarder un lsitign assembleur lineaire ets peu informatif.

Le vrai truc c'est un CALL SYMBOL vs un CALL DWORD PTR[ADRESSE]
Le premier est decodé executé directement, le deuxieme dnecessite l'arrivée dans l'etage de resolution des adresses. A voir sur intel ce que ca implique comme quantité de cycle a attendre.
06/12/2011, 20h18
Flob90

Citation:

Envoyé par koala01

@coda_blank As tu bien vérifié que tu compilais en mode release et non en mode debug :question:

Tu as testé en mode release ?
06/12/2011, 20h25
coda_blank

Citation:

Envoyé par Joel F

ca fait 45 siecles que les processeurs sont pipelinés. Regarder un lsitign assembleur lineaire ets peu informatif.

Le vrai truc c'est un CALL SYMBOL vs un CALL DWORD PTR[ADRESSE]
Le premier est decodé executé directement, le deuxieme dnecessite l'arrivée dans l'etage de resolution des adresses. A voir sur intel ce que ca implique comme quantité de cycle a attendre.

pourquoi le compilateur crée-t-il cette différence ? :?

faut il que j'utilise un autre outil de profiling ?
06/12/2011, 21h32
Emmanuel Deloget

Si tu veux réellement faire des mesures de temps précises, installe un kernel PREMPTRT, le package schedtool, et utilise chrt (ou schedtool) pour mettre le processus en temps réel (priorité 99, scheduler FIFO ou Round Robin). De cette manière, tu va quasiment éliminer les problèmes de mesure liés au scheduler de Linux (pas tout à fait quand même ; mais la latence des thread va passe que 3/6 ms à 50/100 µs, ce qui va quand même rendre les résultats plus fiables).

(A noter que changer le nice du programme ne va pas faire grand chose).
06/12/2011, 21h56
coda_blank

Citation:

Envoyé par Emmanuel Deloget

Si tu veux réellement faire des mesures de temps précises, installe un kernel PREMPTR, le package schedtool, et utilise chrt (ou schedtool) pour mettre le processus en temps réel (priorité 99, scheduler FIFO ou Round Robin). De cette manière, tu va quasiment éliminer les problèmes de mesure liés au scheduler de Linux (pas tout à fait quand même ; mais la latence des thread va passe que 3/6 ms à 50/100 µs, ce qui va quand même rendre les résultats plus fiables).

(A noter que changer le nice du programme ne va pas faire grand chose).

le quoi ? 8O
06/12/2011, 22h21
Emmanuel Deloget

man nice :)
07/12/2011, 00h02
Lightness1024

@Emmanuel : wa, sympa la méthode. ca marche aussi dans une machine virtuelle je suppose ? parce que bon si faut trafiquer son noyau et ses modules on préfère faire ca dans une sandbox que sur sa distrib principale :)

sinon coda_blank je crois que tu as du -g qui traine dans tes flags et ca met la compil en mode debug. faudra penser a compiler en release.

hors sujet: utilise CMake, ca fera des makefile de meilleure qualité. (avec depends, yay \o/)
07/12/2011, 11h48
Joel F

Citation:

Envoyé par coda_blank

pourquoi le compilateur crée-t-il cette différence ? :?

Appel de fonctions versus appels de methode virtuelles, la deuxieme necessite une indirection de plus comme dit precedemment, ce qui se traduit par un saut indirect via une table d'adresse.
07/12/2011, 15h31
jblecanard

Citation:

Envoyé par Lightness1024

@Emmanuel : wa, sympa la méthode. ca marche aussi dans une machine virtuelle je suppose ?

Je pense que non car tu es alors soumis au scheduler de l'OS hôte, que la machine virtuelle ne peut pas voir...
08/12/2011, 01h26
Lightness1024

hmm, parce que les timers haute precision mesure le total real time et pas le total cpu time c'est ca ? comment ça marche d'ailleurs c'est un registre special dans le CPU ?
08/12/2011, 11h30
Emmanuel Deloget

Citation:

Envoyé par Lightness1024

hmm, parce que les timers haute precision mesure le total real time et pas le total cpu time c'est ca ? comment ça marche d'ailleurs c'est un registre special dans le CPU ?

Ca peut marcher de plein de manière différentes - basé sur des IT ou non (CONFIG_NO_HZ, si je ne me trompe pas), en comptant les cycles cpu, etc.

Ce n'est toutefois pas un problème de timer. Lorsqu'on fait tourner un kernel RT dans une machine virtuelle, ce kernel est dépendant de l'architecture sous-jacente. Si le processeur accepte la virtualisation hardware, il lui faut quand même du temps (non contrôlé par l'OS gues, mais par l'OS host) pour passer dans le mode Ring-0 émulé. Dans le cas où la virtualisation hardware n'est pas implémentée, inutile d'aller plus loin : les instructions kernel qui doivent s'exécuter en Ring-0 sont émulées (et là, la notion de performance ne veut plus rien dire).

Au delà de ça, le RT ne peut s'atteindre que si tous les composants de la chaine sont au courant qu'on fait tu temps réel. Problème : l'OS hôte ne sait pas que l'OS guest est un OS RT, donc le logiciel de virtualisation est soumis aux contraintes classiques d'un programme userspace normal (et s'exécute sur un scheduler normal). Dans ces conditions, en comprennant bien que l'OS client RT peut être intérrompu à tout moment par l'OS hote non RT, et que c'est l'OS hote non RT qui rend la main à l'OS client quand il le souhaite, on conçoit facilement qu'aucune contrainte temps réel ne peut être tenue par l'OS virtualisé.

Ceci dit, si tu es sur Debian (je suis sous wheezy/sid), tu as un package kernel PREEMPTRT (3.0.0-1-rt) que tu peux installer en lieu et place de ton kernel courant. Si tu es sur une autre distro, je ne sais pas si c'est possible.
08/12/2011, 13h30
Lightness1024

je vois je vois, et je m'en doutais bien.
mais j'aurais cru que selon ce que voyais le timer, ca pouvait marcher quand meme:
en effet si on imagine que lorsque l'OS client est déschédulé, le timer ne voit pas le trou temporel jusqu'au prochain scheduling, ca pourrait tres bien faire l'affiare, voyez vous ?
donc c'est pour ca que je focalise sur ce "timer" et que je trouve que c'est effectivement un problème de timer. si le timer lisait une valeur qui se "freeze" lorsque l'OS client est deschedulé, ca marcherait quelque soit le kernel hôte.
non ?
08/12/2011, 16h00
Emmanuel Deloget

Citation:

Envoyé par Lightness1024

je vois je vois, et je m'en doutais bien.
mais j'aurais cru que selon ce que voyais le timer, ca pouvait marcher quand meme:
en effet si on imagine que lorsque l'OS client est déschédulé, le timer ne voit pas le trou temporel jusqu'au prochain scheduling, ca pourrait tres bien faire l'affiare, voyez vous ?
donc c'est pour ca que je focalise sur ce "timer" et que je trouve que c'est effectivement un problème de timer. si le timer lisait une valeur qui se "freeze" lorsque l'OS client est deschedulé, ca marcherait quelque soit le kernel hôte.
non ?

Dans ce cas là, l'OS guest ne pourrait jamais être à l'heure :)
08/12/2011, 19h29
Lightness1024

oui absolument. et les applis temps réel tournerait un peu ralenties, ou lagguées. mais ca pourrait etre une option de la machine virtuelle.
09/12/2011, 00h47
Emmanuel Deloget

Citation:

Envoyé par Lightness1024

oui absolument. et les applis temps réel tournerait un peu ralenties, ou lagguées. mais ca pourrait etre une option de la machine virtuelle.

Quel intérêt ? Une appli TR ne joue jamais toute seule : elle dialogue avec quelque chose (matériel, serveur distant, n'importe quoi en fait ; certains protocoles de communication nécessite des temps de réponse maximum définis (je pense au protocole qui permet de gérer les FAX, par exemple)), et c'est ce quelque chose qui a besoin d'avoir des temps de réponse définis et sûr. A moins d'émuler la fonctionnalité traitée, ce qui multiplie le travail, ce n'est pas viable.
09/12/2011, 12h00
Lightness1024

ok. donc conclusion des courses, kernel RT = natif :cry:. fin du semi hors sujet :?