Jako że ostatnio zabrałem się za optymalizację kodu, postanowiłem zmierzyć czas wykonania funkcji. Zacząłem od mierzenia czasu funkcją
clock()
. Kod dawałem w pętle, 10000 iteracji po 10 razy. Wyniki były różne, tłumaczyłem sobie to tym że przecież to nie jest jedyny proces, każdy dostaje swój przydział...
Wszystko ładnie, dopóki nie postanowiłem zmierzyć ilości tików zegara procesora (czy jak tam zwał, poprawcie jeżeli się mylę). Do tego celu użyłem platformy Windows i z tego środowiska będę zamieszczał wyniki (próbowałem również na systemie Linux, wyniki również się różniły).
No to teraz do rzeczy. Do wyżej wymienionego celu użyłem funkcji
__rdtsc()
. Całość wygląda następująco:
char buff[ 32 ];
size_t counter, result = 0;
double other = 0.0, sumx = 0.0, testdbl, average;
DWORD64 timer[ 10 ];
buff[ 31 ] = '\0';
printf( "Function ms_lsdc10:\n" );
printf( "----------------------------------------------------\n" );
for( counter = 0; counter < 10; ++counter )
{
testdbl = counter * 9.3;
timer[ counter ] = __rdtsc();
sumx += ms_lsdc10( testdbl, 5 );
timer[ counter ] = __rdtsc() - timer[ counter ];
printf( "- Pass %d: %ld\n", counter + 1, timer[ counter ] );
}
average =( timer[ 0 ] + timer[ 1 ] + timer[ 2 ] + timer[ 3 ] + timer[ 4 ] + timer[ 5 ] + timer[ 6 ] + timer[ 7 ] + timer[ 8 ] + timer[ 9 ] ) / 10.f;
printf( "----------------------------------------------------\n" );
printf( "Average: %.2f clock cycles\n\n", buff + result, average );
sumx = 0.0;
printf( "Function pow:\n" );
printf( "----------------------------------------------------\n" );
for( counter = 0; counter < 10; ++counter )
{
testdbl = counter * 9.3;
timer[ counter ] = __rdtsc();
sumx += testdbl *= pow( 10.0, 5 );
timer[ counter ] = __rdtsc() - timer[ counter ];
printf( "- Pass %d: %ld\n", counter + 1, timer[ counter ] );
}
average =( timer[ 0 ] + timer[ 1 ] + timer[ 2 ] + timer[ 3 ] + timer[ 4 ] + timer[ 5 ] + timer[ 6 ] + timer[ 7 ] + timer[ 8 ] + timer[ 9 ] ) / 10.f;
printf( "----------------------------------------------------\n" );
printf( "Result: %s with average: %.2f clock cycles\n\n", buff, average );
Całość wydaje się w porządku. Po uruchomieniu wyniki znacznie się różnią, szczególnie pierwsze i kolejne wywołania funkcji. Pomyślałem - no to pewnie priorytet wszystko psuje... Przed pętlami dodaję funkcję
getchar()
, uruchamiam program, włączam CMD jako administrator, wpisuje komendę:
wmic process where name="test.exe" CALL setpriority 256
(dzięki temu ustawiam priorytet czasu rzeczywistego) i klikam ENTER.
I co? I nic... dalej to samo. Stwierdziłem - dobra, może wątek przeskakuje na inny procesor w trakcie działania? No to zakładam blokadę!
Funkcję
SetThreadAffinityMask( GetCurrentThread(), 0x1 );
umieściłem przed pętlami. Dodatkowo dla pewności dodałem funkcję:
SetProcessAffinityMask( GetCurrentThread(), 0x1 );
Dalej to samo.
Oto moje wyniki:
Function ms_lsdc10:
----------------------------------------------------
- Pass 1: 1140
- Pass 2: 637
- Pass 3: 489
- Pass 4: 498
- Pass 5: 485
- Pass 6: 518
- Pass 7: 475
- Pass 8: 494
- Pass 9: 542
- Pass 10: 532
----------------------------------------------------
Result: ╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠ with average: 581.00 clock cycles
Function pow:
----------------------------------------------------
- Pass 1: 62453
- Pass 2: 1672
- Pass 3: 1629
- Pass 4: 5677
- Pass 5: 1606
- Pass 6: 1634
- Pass 7: 1625
- Pass 8: 1658
- Pass 9: 4608
- Pass 10: 1947
----------------------------------------------------
Result: ╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠╠ with average: 8450.90 clock cycles
Moje pytanie: Co tu się dzieje. Nie rozumiem tak nagłej zmiany czasu wykonania tej samej funkcji...
Proszę o pomoc...
edit
-----------------------------------------------------------------
Wyniki z wersji Release:
Function ms_lsdc10:
----------------------------------------------------
- Pass 1: 171
- Pass 2: 176
- Pass 3: 171
- Pass 4: 185
- Pass 5: 171
- Pass 6: 171
- Pass 7: 171
- Pass 8: 171
- Pass 9: 171
- Pass 10: 176
----------------------------------------------------
Result: ►Gs with average: 173.40 clock cycles
Function pow:
----------------------------------------------------
- Pass 1: 171
- Pass 2: 181
- Pass 3: 171
- Pass 4: 171
- Pass 5: 171
- Pass 6: 171
- Pass 7: 181
- Pass 8: 176
- Pass 9: 180
- Pass 10: 176
----------------------------------------------------
Result: ►Gs with average: 174.90 clock cycles
Oraz kompilowany przez CMD: cl main.c
Function ms_lsdc10:
----------------------------------------------------
- Pass 1: 1079
- Pass 2: 475
- Pass 3: 323
- Pass 4: 332
- Pass 5: 338
- Pass 6: 318
- Pass 7: 323
- Pass 8: 327
- Pass 9: 323
- Pass 10: 356
----------------------------------------------------
Result: Ǩ) with average: 419.40 clock cycles
Function pow:
----------------------------------------------------
- Pass 1: 2618
- Pass 2: 2641
- Pass 3: 1558
- Pass 4: 1306
- Pass 5: 4413
- Pass 6: 2879
- Pass 7: 3434
- Pass 8: 3738
- Pass 9: 1249
- Pass 10: 1434
----------------------------------------------------
Result: Ǩ) with average: 2527.00 clock cycles
Kompilator to Visual Studio 2010