Geschwindigkeit ist keine Hexerei, oder doch?

In meinem Programm befindet sich eine Klasse C mit der virtuellen Funktion f und der Funktion g. g ruft f als thread auf

public abstract class C {
  public virtual void f () {}
  public void g () {
    Thread t= new Thread (new ThreadStart (f));
    t.Start ();
  }
}

Desweiteren gibt es eine abgeleitete Klasse C' mit der Funktion f, die eine komplexe Berechnung durchführt.

public class C' : C {
  public override void f () {...}
}

Und es gibt noch die Klasse C'', abgeleitet von C'.

public class C'' : C' {
  public override void f () {base.f ();}
}

Die entsprechenden Objekte o1 und o2 gibt es auch.

C o1=new C' (); C o2=new C'' ();

Die Aufrufe o1.g () und o2.g () sollten genau das gleiche machen und das tun sie auch. Allerdings dauert die Berechnung beim Aufruf von o1.g () 50sec und bei o2.g () 29sec.
Wie kann das sein?

Und wie hast Du gemessen, um Messungenauigkeiten zu vermeiden?

führe den test mehrmals durch, da der JIT compiler ebim ersten aufruf erstmal den IL code übersetzen muss.

außerdem ist deine beschreibung undurchsichtig. in abstrakten code verfasst wäre es einleuchtender, was du genau meinst.

Und wie hast Du gemessen,[...]

Hast du beim Messen auch so lange gewartet, bis alle Threads wirklich fertig sind?

Bitte benutze [csh****arp]-Tags.

Gruß,
dN!3L

Ich habe die Berechnung mehrmals innerhalb eines Programm-Aufrufs durchgemessen, mit dem selben Ergebnis, die Zeiten sind konstant.
Gemessen wird ganz simpel, indem in einem Timer-Objekt (250ms) geprüft wird ob der Thread noch aktiv ist. Die Genauigkeit braucht gar nicht so hoch sein bei den dicken Zeitunterschieden.
Dass es mit dem JIT compiler zu tun haben kann hab ich auch schon gedacht, da ja die Einsprungadressen von virtuellen Funktionen erst zur Laufzeit ermittelt werden können aber sowohl C' als auch C'' sind abeleitete Klassen.

Ich habe nun mal die Klasse C' folgendermaßen geändert:

public class C' : C {
  protected void calc () {...}
  public override void f () {
    calc ();
  }
}

Also die Berechnung wurde in eine lokale Funktion der Klasse C' geschoben.
Nun werden nur noch 29s benötigt!

Ich behaupte einfach mal ganz frech: Code in virtuellen Funktionen wird nicht kompiliert.

Dass es mit dem JIT compiler zu tun haben kann hab ich auch schon gedacht, da ja die Einsprungadressen von virtuellen Funktionen erst zur Laufzeit ermittelt werden können aber sowohl C' als auch C'' sind abeleitete Klassen.

was?... ne da hast du was komplett missverstanden.

Gemessen wird ganz simpel, indem in einem Timer-Objekt (250ms) geprüft wird ob der Thread noch aktiv ist.

ungewöhnlich + ineffektiv + nicht aussagekräftig.

verwende den stopwatch und schreibe z.b. in die debugausgabe oder in eine datei oder wo auch immer hin.

Ich behaupte einfach mal ganz frech: Code in virtuellen Funktionen wird nicht kompiliert.

wieso das denn?

Hi Sengir,

wenn du wissen willst, was hier abgeht, musst du dir wohl oder übel die erzeugten ASM-Befehle anzeigen lassen.
(Als Release vom Visual Studio aus ausführen und in den Debugging Optionen unbedingt das Häkchen bei "JIT-Optimierungn beim Laden von Module unterdrücken" entfernen! Dann kannste Breakpointen und mit rechtsklick Disassembly anschauen)

Und du solltest kein "abstraktes" Beispiel aufzeigen, sondern ein konkretes kleines Snippet, bei dem der Effekt ganz klar festzustellen ist.
Also versuch doch mal deinen Code zu extrahieren und zu kondensieren auf ein minimalistisches reales Beispiel, bei dem der Effekt auftritt.

Es gibt nämlich noch zahlreiche Faktoren zwischen Himmel und Erde (zwischen virtual Methoden und nicht) die den JIT-Optimizer beeinflussen.
Beispielsweise before-field-init oder precies semantics beim Initialisieren irgendwelcher statischer Member. Oder oder oder ...
Also bitte ein konkretes Beispiel.
Sonst ist alles nur heiteres Gerate!

Achja und verwende bitte System.Diagnostics.StopWatch. Sonst entbehrt das Gerate auch noch jeglicher Grundlage. 😉

beste Grüße
zommi

Ich hab mal 'ne Konsolenanwendung geschrieben, die genau dieses Problem behandelt. Die Laufzeitunterschiede sind zwar nicht so extrem wie in meiner Anwendung aber trotzdem klar zu erkennen.

using System;
using System.Diagnostics;

namespace virtuell {
   abstract class class0 {
      public double d;
      protected double func (int i) {
         return Math.Pow (Math.Sin (i), Math.Cos (i+1));
      }

      public virtual void f () {
         for (int i= 0; i<100000; i++)
            d=func (i);
      }
   }

   class class1 : class0 {
      public override void f () {
         for (int i= 0; i<100000; i++)
            d=func (i);
      }
   }

   class class1a : class0 {
      protected void calc () {
         for (int i= 0; i<100000; i++)
            d=func (i);
      }

      public override void f () {
         calc ();
      }
   }

   class class2 : class1 {
      public override void f () {
         base.f ();
      }
   }

   class Program {
      static Stopwatch watch= new Stopwatch ();
      static int probes=100;

      static void Main (string[] args) {
         class0 c1= new class1 ();
         class0 c1a= new class1a ();
         class0 c2= new class2 ();
         TestClass (c1);
         TestClass (c1a);
         TestClass (c2);
      }

      static void TestClass (class0 c) {
         Console.Write (c.ToString ()+": ");
         watch.Reset ();
         watch.Start ();
         for (int i=0; i<probes; i++)
            c.f ();
         watch.Stop ();
         Console.WriteLine ((watch.ElapsedTicks/probes).ToString ());
      }
   }
}

Ich hab das mal bei mir getestet, mit 1000 Aufrufen (Probes) bekomme ich folgende Ergebnisse:

1. Durchlauf:

virtuell.class1: 133663951
virtuell.class1a: 133739767
virtuell.class2: 133507377

2. Durchlauf:

virtuell.class1: 133814146
virtuell.class1a: 134256705
virtuell.class2: 133892874

3. Durchlauf:

virtuell.class1: 133667046
virtuell.class1a: 134503184
virtuell.class2: 133652840

Alles in allem, würde ich behaupten, es gibt kaum einen Unterschied...
Christian

Yep, ist der Release-Mode. Bei mir sieht das Ergebnis allerdings folgendermaßen aus (bei 1000 probes):

virtuell.class1: 47573
virtuell.class1a: 45130
virtuell.class2: 45097

Hi,

dreh mal aus Spaß die Reihenfolge um:

TestClass (c1);
TestClass (c1a);
TestClass (c2);

wird zu (beispielsweise)

TestClass (c2);
TestClass (c1);
TestClass (c1a);

😉
beste Grüße
zommi

Yep, ist der Release-Mode. Bei mir sieht das Ergebnis allerdings folgendermaßen aus (bei 1000 probes):

virtuell.class1: 47573
virtuell.class1a: 45130
virtuell.class2: 45097

Sind die Werte denn reproduzierbar?

Der Grund, warum ich mehrere Durchläufe gemacht hat, liegt darin, daß sich nicht nur die absoluten Werte, sondern die Verhältnisse jedesmal ändern. Und das bei 1000 Aufrufen statt 100.

Bei deiner Testanwendung ist mir aufgefallen, daß die meiste Rechenzeit für die mathematische Berechnung in der func-Methode benötigt wird. Beweisen willst du aber, daß virtuelle Methoden extrem langsam ausgeführt werden (weil sie nicht kompiliert werden?). Daher finde ich den Test nicht aussagefähig, für das was du behauptest.

Andererseits ist klar, daß die virtuellen Aufrufe länger dauern, weil die Adresse der Methode zuerst ausgelesen werden muß, bevor dorthin gesprungen wird. Wie das ganze Funktionert, und daß virtuelle Methoden auch kompiliert werden kannst du aber nachlesen. Für solche extremen Unterschiede wie du in deinem ersten Post behauptest, sehe ich jedenfalls keine Anhaltspunkte.
Christian

Sind die Werte denn reproduzierbar?

Ja, sind sie. Ich hab 10 mal das Programm gestartet und die Änderungen betragen nur +/-100 ticks.

dreh mal aus Spaß die Reihenfolge um:

virtuell.class2: 45666
virtuell.class1: 45061
virtuell.class1a: 45666

Wenn ich die Reihenfolge ändere kommt das Ergebnis raus, was ich auch erwarten würde. (Auch hier habe ich das Programm mehrmals gestartet mit unbedeutenden Abweichungen im Ergebnis)

Hallo Sengir,

halten wir einfach mal fest: Anfänglich (50sec vs. 29sec) hast du offensichtlich vollkommen falsch gemessen und die Messungen am Ende zeigen im Rahmen der Messungenauigkeit das erwartete Ergebnis.

Natürlich ist es wegen des zusätzlichen Methodenaufrufs nicht schneller, wenn f'' per base f' aufruft als wenn direkt f' aufgerufen wird. Da in deinem Messprogramm der Aufwand aber nicht in den Methodenaufrufen liegt, sondern in der aufwändigen Math.Pow-Schleife, geht der geringe Unterschied durch den zusätzlichen Methodenaufruf in der Laufzeitschwankung der Math.Pow-Schleife vollkommen unter. Die Tatsache, dass durch den JIT der jeweils erste Messlauf benachteiligt wird, tut ihr übriges.

Oder anders gesagt: Wer misst, misst Mist. -)

Weitere Untersuchungen kannst du dir aus meiner Sicht sparen. Durch eine zusätzliche Unterklasse und einen zusätzlichen Methodeaufruf, lässt sich nichts beschleunigen. Im Gegenteil wird es dadurch (minimal) langsamer. Alle Messungen, die was anderes sagen, sind in sich falsch oder falsch interpretiert.

herbivore

Oder anders gesagt: Wer misst, misst Mist. -)

Kann man nicht besser ausdrücken 😉.

Das was wirklich wichtig ist in Sachen Performance sind Big-O und Big-Theta... Das Big-O ist bei beiden Methoden gleich. Das Theta ist bei der abgeleiteten Klasse durch den Aufruf von base.f() geringfügig (um 1) größer, da ein weiterer Methodenaufruf vorgenommen wird.

Eure Erklärungen klingen für mich auch logisch. Trotzdem scheint mein Programm nicht viel von Logik zu halten. Noch mal ein kurzer Schnipsel aus der abgeleiteten Klasse

protected void CalculatePass (int blockWidth) {
...
}
   
protected new void DoCalculation () {
   int blockSize= maxBlockSize;
   while (blockSize>0) {
      CalculatePass (blockSize);
      blockSize>>=1;
   }
}

public override void CalcThread () {
   DoCalculation ();
}

Die virtuelle Funktion CalcThred wird aufgerufen um die Berechnung zu starten, Berechnungsdauer: ca 30 Sekunden.
Wenn ich nun auf die lokale DoCalculation-Funktion verzichte und die Schleife direkt im CalcThread unterbringe erhöht sich die Berechnungszeit auf ca. 50 Sekunden. Und ja: ich habe mehrmals die Berechnungszeit gemessen und bei sooo grossen Unterschieden reicht auch ne einfache Uhr um genau genug zu messen 😉

Aber es beruhigt mich, dass ich nicht der einzige bin, der keinen blassen Schimmer hat woran das liegen könnte 😉 Normal ist das Verhalten nicht, aber es ist so und da ich das nun weiß werde ich entsprechend weiterentwickeln.

Trotzdem Danke für Eure Ideen und Bemühungen

ich würde eher sagen das du irgendwo auf synchronisierung warten musst und daher die lange wartezeit produzierst? du hast ja selbst gemessen, das das nicht sein kann, das es doppelt so lange braucht, daher musst du dich auch nciht mit sarkasmus bedecken.

wir kennen nicht deinen code daher können wir nur raten aber eins ist 100% gewiss: der fehler ist in deinem code wenn er statt 30s ganze 50s braucht.

Das hat nix mit Sarkasmus zu tun. Es ist ein Fehler da für den es offensichtlich keine Erklärung gibt. Es kann gut sein, dass irgendwo in den Berechnungen ein Fehler zu finden ist aber dass allein durch das Umstellen dieser paar Zeilen dieser Fehler provoziert wird ist mir völlig schleierhaft.
Was genau meinst Du mit Synchronisierung? Dass der Berechnungsthread auf Ergebnisse von anderen Threads warten muss? Dem ist nicht so und da würde auch das Umstellen dieses Codeschnipsels keinen Einfluss drauf haben.

Hi,

Es ist ein Fehler da für den es offensichtlich keine Erklärung gibt.

Fehler? Glaub ich kaum. Ich tippe auf Spezifikation 🙂
Und wenn, dann muss aus "offensichtlich keine Erklärung" ein "keine offensichtliche Erklärung" werden. So lässt sich weiter diskutieren 😉

Aber ich kann mich nur nochmals selbst zitieren:

Also versuch doch mal deinen Code zu extrahieren und zu kondensieren auf ein minimalistisches reales Beispiel, bei dem der Effekt auftritt.

Dein vorheriges Snippet hat ja offensichtlich nicht denselben Effekt gezeigt. 🤔
Wenn du nicht den gesamten Code posten willst, ist das ja ok, aber wie gesagt:
An dem Brocken "wenn ich das in eine Funktion auslager, wirds fast doppelt so schnell" wird eben auch unsere Glaskugel nicht satt 😉

Und da die CLR eben ein komplexes Gebilde ist, gibt es zu viele Faktoren, als dass wir alle durchraten könnten.
Also sei gnädig und wirf uns ein paar reale Anhaltspunkte hin.

Oder vergleich die IL-Code ausgaben, wenn nicht sogar die ASM-Disassemblys. Oder schalt den PerformanceMonitor (perfmon) dazu, debugge dich mit WinDebug und der SOS-Erweiterung rein, hol dir nen Performance Profile für .Net.
All das kann aber nur der machen, der den Code hat, bei dem der Effekt auftritt.

beste Grüße
zommi

Hallo Sengir,

du verwendest protected **new** void DoCalculation. Das hat bestimmt zur Folge, dass in CalcThread eine ganz andere Version von DoCalculation aufgerufen wird, als wenn du DoCalculation direkt aufrufst. Zumindest würde das, das Verhalten erklären. Entscheidend ist bei new der statische und nicht der dynamische Typ des Objekts. Das ist in 99,999% der Fälle nicht das, was man will. Deshalb ist new in meinen Augen eine Krankheit und die fast nie bewirkt, das was man eigentlich will.

herbivore

Das new ist da, weil die Funktion bereits in der Parent-Klasse definiert wurde und ich hier eine neue Definition der Funktion benötige. Ich kann die Funktion auch einfach anders benennen, ist eh viel schöner, da sie ja nix mit der gleichnamigen Funktion der Parent-Klasse zu tun hat.

Aber ich glaube ich habe den Fehler gefunden: ich habe bisher das Projekt immer nur MIT Trace-Konstanten erzeugt. Wenn ich es ohne Trace-Konstanten erzeuge gibt es keinen zeitlichen Unterschied mehr zwischen den Versionen.