Ausführzeit von Funktionen

Hallo allerseits,

ich habe folgende Funktion:

private func CalcWake(int windDirection, int saveTo) {

    var t = GetSystemTime(7) + GetSystemTime(6) * 1000 + GetSystemTime(5) * 60000;
   
    /*Code, den ich hier mal weggelassen hab um ihn nicht erklären zu müssen*/

    Log("t: %v", GetSystemTime(7) + GetSystemTime(6) * 1000 + GetSystemTime(5) * 60000 - t);
   
    CycleWindMap("CalcWakeInnerLoop", windDirection < 180, Inside(windDirection, 90, 179), start, stop, startDir, windDirection, saveTo, turbCounts);
}


CycleWindMap ruft die angegebene Funktion für jedes Element eines Arrays auf.

Das Problem:

Als Ergebnis bekomme ich immer "t: 0", der Script Profiler gibt jedoch das hier aus:
00999ms MAW5::CalcWake
00798ms MAW5::CalcWakeInnerLoop


Wo kommen diese 200 ms Unterschied her?

Danke im Voraus

Ich hätte dazu mindestens zwei Theorien:
1) Rufst Du das lokal oder im Netzwerkmodus auf? Siehe Doku von GetSystemTime().
2) Windows?

1: Lokal
2: Windows 7

Ich habe die Ausgabe der Zeitdifferenz nochmal unter den Aufruf von CycleWindMap gesetzt
Anscheined macht es einen Unterschied, mit welchen Parametern die Funktion aufgerufen wird
windDirection == 90:

t: 0
t: 481

00481ms  MAW5::CalcWake
00467ms  MAW5::CalcWakeInnerLoop


windDirection == 270:

t: 0
t: 525

00526ms  MAW5::CalcWake
00312ms  MAW5::CalcWakeInnerLoop

Jetzt sehen die Zahlen ja gut aus. CycleWindMap müsste auch irgendwo in der Ausgabe des Profilers auftauchen.

Ich habe alle sonstigen Aufrufe im Script zu CycleWindMap entfernt, jetzt bekomme ich diese Statistik:

t: 0
t: 621

00623ms  MAW5::CalcWake
00616ms  MAW5::CycleWindMap
00398ms  MAW5::CalcWakeInnerLoop


Ich verstehe immer noch nicht, wieso die Ausführzeit von CalcWakeInnerLoop so viel kürzer ist als die von CalcWake oder CycleWindMap, wenn alles, was nicht der Aufruf von CalcWakeInnerLoop ist, 0ms braucht.

Der Aufwand liegt offenbar in CycleWindMap. Wie sieht diese Funktion denn aus?

private func CycleWindMap(string functionName, bool reverseI, bool reverseJ) {
    for(var i = reverseI * xMap; Inside(i, 0, xMap); i += reverseI * -2 + 1) {
        for(var j = reverseJ * yMap; Inside(j, 0, yMap); j += reverseJ * -2 + 1) {
            Call(functionName, i, j, Par(3), Par(4), Par(5), Par(6), Par(7), Par(8), Par(9));
        }
    }
}

Das sieht grundsätzlich ok aus. Ich könnte mir schon vorstellen, dass von dieser Schleife deine 20% Overhead herkommen.

Ich gehe mal davon aus, dass du die Frage hier stellst, weil der Code nicht schnell genug läuft. Daher würde ich dir empfehlen, ein paar manuelle Optimierungen mit dem Profiler auszuprobieren (es ist jeweils unklar, ob die Änderungen wirklich eine Verbesserung bringen):

- Die Berechnung von Invarianten aus der Schleife rausziehen.  Also das aus dem 1. und 3. Teil der for-Schleifen.
- Inside inlinen, also direkt 0 &lt;= i &amp;&amp; i&#160; &lt; xMap
- Direkter Funktionsaufruf statt Call. Ich meine, dass lokale Funktionsaufrufe statisch gebunden werden, sodass nicht mehr anhand des Namens gesucht werden muss.
- ... statt Par()-Aufrufe

Du hast Recht, es liegt wirklich an CycleWindMap.

Anscheinend entsteht der größte Zeitaufwand durch das Übergeben der Parameter an die aufgerufene Funktion, da lässt sich leider nichts machen.
Meine ursprüngliche Frage ist damit beantwortet, danke für die Tipps.

Jedoch habe ich noch eine weitere Frage:

Mir ist beim Testen aufgefallen, dass ich die Laufzeit von CycleWindMap von ca. 200 ms auf 4 ms (!) reduzieren kann, wenn ich statt
CycleWindMap("Funktion", 0, 0)
CycleWindMap("Funktion", 1, 1)
aufrufe (also rückwärts zähle anstatt vorwärts).
Das löst natürlich alle Performance-Probleme, aber woran liegt das?

>Anscheinend entsteht der größte Zeitaufwand durch das Übergeben der Parameter an die aufgerufene Funktion, da lässt sich leider nichts machen.


Hast du da mal versucht, ob ... statt der einzelnen Par-Aufrufe schneller ist?

>Mir ist beim Testen aufgefallen, dass ich die Laufzeit von CycleWindMap von ca. 200 ms auf 4 ms (!) reduzieren kann


Seltsam, da habe ich keine Erklärung für.

Edit: Hast du auch überprüft, dass du keinen off-by-one-Fehler in deiner Schleife hast? Mit Inside() läuft die Schleife tatsächlich von 0 bis xMap bzw. yMap (inklusive), anders als weiter oben von mir angenommen. Daher sollte xMap maximal LandscapeWidth()-1 sein und yMap entsprechend. Wenn du Inside() so ersetzt hast wie in meinem Post oben, dann ist klar, warum es rückwärts schneller läuft: in dem Fall macht die Schleife nämlich gar nichts.

>Hast du da mal versucht, ob ... statt der einzelnen Par-Aufrufe schneller ist?


Es liegt haupsächlich am Übergeben von i und j:
Wenn ich mit Call eine leere Funktion aufrufe bekomme ich folgende Werte für xMap = 500 und yMap = 500
Call(functionName)    2300ms
Call(functionName, i, j)    6400ms
Call(functionName, i, i, j, j)    10500ms
Call(functionName, ...) (mit 9 übergebenen Parametern an CycleWindMap)    2380ms
Call(functionName, Par(2), Par(3), Par(4), Par(5), Par(6), Par(7), Par(8), Par(9))    2480ms

... ist also etwas schneller

Bei rückwärts zählen bekomme ich ca. 200ms ohne i und j, 250ms mit und 300ms mit weiteren Parametern (Unterschied zwischen ... und Par konnte ich nicht feststellen)

>Wenn du Inside() so ersetzt hast wie in meinem Post oben, dann ist klar, warum es rückwärts schneller läuft: in dem Fall macht die Schleife nämlich gar nichts.


Ich habe die Funktion verwendet die ich weiter oben gepostet habe, die übergebene Funktion wurde auch für alle Werte von i und j aufgerufen.

>Daher sollte xMap maximal LandscapeWidth()-1 sein und yMap entsprechend.


xMap ist (LandscapeWidth() - 1) / 15 und bezieht sich auf einen Array mit Länge xMap + 1