Programmoptimierungen, Laufzeit, Windows

[CPUFreak]

Hallo,

ich führe momentan einige Performancetests mit 2 Funktionen durch und nutze dazu QueryPerformanceCounter() um die CPU Ticks zu messen.

Dabei habe ich ein merkwürdiges Problem. Ich führe insgesamt 5 Runden durch, in der ich eine Funktion jeweils 100000 aufrufe. Die zwei Funktionen führen bestimmte arithmetische Operationen durch.

Merkwürdigerweise ist in der ersten Runde erwartungsgemäß Funktion 1 stehts schneller als Funktion 2. Doch plötzlich, ab der zweiten Runde ändert sich das Verhältnis scheinbar dramatisch. Funktion 1 ist plötzlich 10x schneller als noch im ersten Durchlauf. Die Geschwindigkeit von Funktion 1 bleibt wie erwartet annähernd konstant.

Funktion 2 hat denselben Ausführungspfad, wie in der ersten Runde. Daran kann es also nicht liegen. Die Funktion führt einige Shifts usw. durch.

Hat jemand eine Idee wie es zu dieser Änderung kommen kann?

Optimiert Windows hier vielleicht etwas? Ich kann mir das nicht erklären.

[mess-freak]

Fehler im Messcode

[Shade Of Mine]

Nimm einen echten Profiler fuer solche Tests.

Es kann eine Messverzerrung sein (wer misst misst mist) oder es kann damit zu tun haben, dass die eine Funktion bei den Speicherzugriffen page faults produziert, die andere aber nicht. Das waere zB eine erklaerung warum ein 2. Aufruf schneller sein kann als der erste - da die essentiellen daten dann im cache liegen.

so einfach laesst sich das ganze aber nicht sagen und wenn es dir um millisekunden oder so geht, dann sind alle messungen mehr als ungenau.

[CPUFreak]

Hi,

danke schonmal für die hilfreichen Antworten.

Was mich dabei allerdings verwundert ist, das die 1 Funktion in der ersten Runde stets 40% schneller läuft als Funtion 2. Ab der 2 Runde dreht sich das dann wie angesprochen dramatisch.

An Mesfehlern kann das nicht liegen, diese würden sich relativieren.

Mit ist das Ganze ziemlich schleierhaft. Ich habe die Iterationen auf 10000000 erhöht umd von den engen Zeitfenstern wegzukommen und so ein zuverlässigeres Ergebnis zu erhalten.

Es bleibt dabei. Funktion 2 läuft ab der 2 Runde um die 10x schneller als Funktion 1.

Das merke ich selbst, weil ich bei diesen hohen Iterationen die Zeit in Sekunden sehe und erkennen kann, das die Funktion 2 plötzlich erheblich schneller läuft als im Durchgang 1.

Insgesamt gibt es 5 Runden, dieser Art:

__int64 testFunction1(size_t n)
{
    unsigned int i;
    __int64 c = 0;

    for(i = 0; i < n; i++) {
        c += fast_multi(i & 0x000000FF, ((i+2) & 0x000000FF));
    }

    return c;
}

Die erste Funktion bleibt schließlich wie erwartet konstant über die 5 Runden. Nur die 2 Funktion spielt mir üble Streiche, indem sie ab der 2 Runde beginnt drastisch schneller zu laufen. In den letzten 4 Runden bleibt ihre Ausführungsgeschwindigkeit auch konstant.

Nur in der ersten Runde läuft sie deutlich langsamer.

Ich habe die beiden Funktionen auch schon getauscht, um Fehler durch die Reihenfolge auszuschalten - ohne Erfolg. Es bleibt bei dieser komischen Eigenart.

[CPUFreak]

Achja, welchen Profiler würdet ihr mir unter Windows empfehlen?

[Ö.ö]

in welcher größenordnung bewegen sich denn die gemessenen zeiten? der aufruf der winapi funktion benötigt nämlich auch mal mehr, mal weniger zeit und bei solchen geringfügigen arithmetischen operationen kann das schon mal ins gewicht fallen.

[CPUFreak]

Ö.ö schrieb:

in welcher größenordnung bewegen sich denn die gemessenen zeiten? der aufruf der winapi funktion benötigt nämlich auch mal mehr, mal weniger zeit und bei solchen geringfügigen arithmetischen operationen kann das schon mal ins gewicht fallen.

1. Runde:

Funktion 1: 850000 CPU Ticks (0.23249 s)
Funktion 2: 3760987 CPU Ticks (1.05068 s)

2. Runde:

Funktion 1: 900000 CPU Ticks (0.25709 s)
Funktion 2: 8470 CPU Ticks (0.00236 s)

3. Runde:

Funktion 1: 800000 CPU Ticks (0.22172 s)
Funktion 2: 7987 CPU Ticks (0.00168 s)

Zu erwähnen währe noch, das Funktion 1 Berechnungen mithilfe zweier Array Tabellen durchführt, während Funktion 2 eine Schleife mit diversen Bitshifts usw. nutzt.

[CPUFreak]

Ich glaube das Problem hat sich erledigt. Ich hatte davor die 5 Runden folgendermaßen realisiert:

// 1. Round
QueryPerformanceCounter(&start_ticks); 
function1(n);
QueryPerformanceCounter(&end_ticks); 
cputime.QuadPart = end_ticks.QuadPart- start_ticks.QuadPart;

QueryPerformanceCounter(&start_ticks); 
function2(n);
QueryPerformanceCounter(&end_ticks); 
cputime.QuadPart = end_ticks.QuadPart- start_ticks.QuadPart;

// 2. Round
QueryPerformanceCounter(&start_ticks); 
function1(n);
QueryPerformanceCounter(&end_ticks); 
cputime.QuadPart = end_ticks.QuadPart- start_ticks.QuadPart;

QueryPerformanceCounter(&start_ticks); 
function2(n);
QueryPerformanceCounter(&end_ticks); 
cputime.QuadPart = end_ticks.QuadPart- start_ticks.QuadPart;

//...

Nun habe ich die Runden in eine eigene Funktion ausgelagert. Und plötzlich bekomme ich die erwarteten Ergebnisse. Das heißt Funktion 2 bleibt über alle Runden annähernd konstant und wird nicht mehr plötzlich nach der 1. Runde schneller ausgeführt.

Keine Ahnung warum? Das dürfte doch keinen Unterschied machen ob ich die Runden in main 5x hintereinander aufrufe oder 5 mal über eine Funktion?

[Bitte ein Bit]

Könnte ich mal einen Blick in die testFunction2() und fast_multi() haben ?

Es dürfte theoretisch keinen UNterschied machen, doch irgentwie brechen ja die Ergebnisse komplett in testFunction2() zusammen.

Dazu hätte ich auch mal eine Frage: Stimmen die Ergebnisse überhaupt ? Bzw. ist TestFunction1(10000) = TestFunction2(10000) ?

[CPUFreak]

Bitte ein Bit schrieb:

Könnte ich mal einen Blick in die testFunction2() und fast_multi() haben ?

Es dürfte theoretisch keinen UNterschied machen, doch irgentwie brechen ja die Ergebnisse komplett in testFunction2() zusammen.

Dazu hätte ich auch mal eine Frage: Stimmen die Ergebnisse überhaupt ? Bzw. ist TestFunction1(10000) = TestFunction2(10000) ?

Ja, beide Funktionen werden natürlich mit derselben Zahl n aufgerufen. Um Fehlern vorzubeugen nutzen alle ein Makro das einmal definiert wird oder einen Wert der per Kommandozeile übergeben wird.

Das eigenartige "Problem" ist allerdings verschwunden, nachdem ich die Aufruffunktion auch nochmal ausgegliedert habe. Ich habe keine Ahnung warum, aber der Compiler scheint mir üble Optimierungsstreiche zu spielen.

Mein Fazit nach diesem Benchmark ist, traue keinem Benchmark, den du nicht selbst gefälscht hast.

Die Funktion fast_multi() ist die C Umsetzung des A 1 in Kapitel 3:

http://www.dice.ucl.ac.be/crypto/files/publications/pdf254.pdf

[testing-freak]

mach solche tests am besten mit 'nem processor ohne instruction-caching und ohne multitasking-OS bzw. ohne interrupts.

[CPUFreak]

testing-freak schrieb:

mach solche tests am besten mit 'nem processor ohne instruction-caching und ohne multitasking-OS bzw. ohne interrupts.

Das ist leider das Problem bei der Komplexität moderner Architekturen und Compiler. Hier spielen soviele andere Dinge mit ein, das man gewisse Benchmarks wirklich nur in einem begrenzten Rahmen vernünftig durchführen kann, so dass diese auch eine allgemein gültige Aussagequalität besitzen.

Das erinnert mich an den Java vs. C++ Benchmark. Der wurde auch so "gedreht" das am Ende das pauschale Fazit im Raum stand, Java wäre schneller als C++.

Ich habe mir erst kürzlich einen optimierten C++-Quellcode angesehen. Da wurde mit SSE2 und Co. Befehlen mittels Inline Assembler hantiert, das einem schwindelig wurde.

So ein feiner Profiler wäre ja Intels VTune...

[Bitte ein Bit]

Naja, wenn man den Test ordentlich durchführt, dürften die Ergebnisse selbst auf einem Multitasking-OS nicht so derb schwanken, wie dies bei der Testfunktion2 der Fall ist. (Testprogramm mit hoher Priorität starten, alle aktiven Programme auf das nötigste abschalten, ...).

Ein kurzer Flug über die Algorithmen zeigte mir dass beide Algorithmen linear in ihrer Laufzeit sind, d.h. die Laufzeiten beider Algorithmen dürfte sich nur in einer Konstante unterscheiden. Und das tun sie hier in keinster Weise.

Ist das Ergebniss eigentlich reproduzierbar ? Kann man den Test so 10x laufen lassen und es kommt immer wieder das selbe Ergebniss raus ??? Was passiert eigentlich wenn man die Testreihenfolge ändert ? Bsp: Erst alle Tests mit testFunction1() durchlaufen lassen und dann mit testFunction2(). Wie sieht das Ergebniss aus, wenn die Optimierung ausgeschaltet wird ?

[CPUFreak]

Bitte ein Bit schrieb:

Naja, wenn man den Test ordentlich durchführt, dürften die Ergebnisse selbst auf einem Multitasking-OS nicht so derb schwanken, wie dies bei der Testfunktion2 der Fall ist.

Das ist mir durchaus bewußt und deshalb auch meine Verwunderung darüber.

Bitte ein Bit schrieb:

Ein kurzer Flug über die Algorithmen zeigte mir dass beide Algorithmen linear in ihrer Laufzeit sind, d.h. die Laufzeiten beider Algorithmen dürfte sich nur in einer Konstante unterscheiden. Und das tun sie hier in keinster Weise.

Das habe ich bereits anmerken lassen. Beide Algorithmen haben die Komplexität O(n). Daran kann es also nicht liegen. Diese Ausführungspfade sind stets dieselben.

Bitte ein Bit schrieb:

Ist das Ergebniss eigentlich reproduzierbar ? Kann man den Test so 10x laufen lassen und es kommt immer wieder das selbe Ergebniss raus ??? Was passiert eigentlich wenn man die Testreihenfolge ändert ? Bsp: Erst alle Tests mit testFunction1() durchlaufen lassen und dann mit testFunction2(). Wie sieht das Ergebniss aus, wenn die Optimierung ausgeschaltet wird ?

Ja, es war immer wieder reproduzierbar. Ob 5 oder 30 Runden war egal. Nach der ersten Runde kehrte sich die Perfomance von F2 drastisch um und blieb dann konstant, also wie erwartet, über alle anderen Runden. Das sagte ich aber bereits.

Es war immer nur die erste Runde, die erwartungsgemäß verlief und sich von allen anderen Runden unterscheidete. Dabei spielte es keine Rolle ob ich F1 zuerst oder F2 zuerst aufrief.

Und ich weiß auch nicht, warum sich das durch die Auslagerung verändert hat.

Wie auch immer, das Phänomen ist verschwunden. Ich kann damit leben, das ich den Grund dafür nicht kenne. Thats life!