# Mysteriöser Benchmark: For-Loop



## Guest (13. Dez 2007)

Gegeben ist folgender Code:


```
public class looptest
{
 public static void main (String argv[])
 {
  int i, j, k , l, m;
  long t;

  System.out.println("Start!");

  t=System.currentTimeMillis();

  j=0; k=0; l=0;

  for(m=0;m<10;m++)    //DER KNACKPUNKT
  for(i=0;i<1000000000;i++)
     {
      j++;
      k+=l*j+i;
      k++;
     }

  t=System.currentTimeMillis()-t;

  System.out.println("Hello World: "+j+" time="+t+"Code: "+k);
 }

}
```

Unter Linux Kernel 2.6 in der Jave SE build 1.6.0_03-b05 passiert nun folgendes:


Im Original oben dauert ein Durchlauf:

./java loopteset
Dauert: 91 Sekunden


Entferne ich die äussere For-Schleife, erhalte ich folgende Werte:

./java loopteset
Dauert: 4 Sekunden


Als Zeit wird ja nur die Zeit der Schleife(n) gezählt, d.h. der Overhead beim Laden der VM wird nicht mitgezählt.


Wie kann es bitteschön sein, dass das 10fache Durchlaufen der 1-Milliarde-Schleife
91 Sekunden dauert und das 1fache Durchlaufen 4 Sekunden?

91 Sekunden zu 4 Sekunden verhält sich nicht wie 10 zu 1.

Wenn, dann müsste doch das Programm mit den 10 Iterationen immer schneller sein als das mit nur einer, da sich hier etwaige Start-Effekte verlieren (parallel gestartete Verwaltungs-Threads in der VM die anfangs noch arbeiten und anfangs wertvolle CPU-Zeit verbrauchen).

Woran kann das liegen?


Vielen Dank!


Thomas


----------



## Gast (13. Dez 2007)

Im letzten Absatz meine ich mit "immer schneller" natürlich nicht absolut sondern geteilt durch die Iterationen...


----------



## Wildcard (13. Dez 2007)

Mirkobenchmarks dieses Kalibers sind bei einer Hotspot VM völlig wertlos und beinhalten keinerlei Aussage.


----------



## Gast (13. Dez 2007)

Kannst Du mir hierzu bitte ein paar Hintergrundinfos (z.B. Stichworte) geben, warum das so ist, da es sich dem gemeinen Delphi-Programmierer direkt nicht erschliesst.

Kann man beschriebene "Anomalie" umgehen/verrignern?
Der "Mikrobenchmark" hat nämlich einen für meine Zwecke ernsten Hintergrund.

Vielen Dank!


----------



## Wildcard (13. Dez 2007)

Davon abgesehen das 4 Sekunden generell zu kurz für irgendwelche Aussagen ist, sind moderne Hotspot/JiT Compiler hochoptimierend.
Der erste Optimierungsschritt erfolgt schon zur Übersetzung, das Resultat kann sich also deutlich von deinem Quellcode unterscheiden.
Anschließend kommt die Laufzeitoptimierung hinzu. Der Hotspot und der JiT bemerken wenn eine Routine lange läuft oder häufig aufgerufen wird. Nach einem Schwellwert X wird der Bytecode stärker optimiert, Methoden ge 'in-lined', die Berechnungen auf deine Hardwarearchitektur zugeschnitten und gegebenenfalls der Bytecode in ein natives Kompilat umgewandelt.
Als zusätzliche Schwierigkeit hast du das generelle Problem das jederzeit der GC aktiv werden kann und die Messergebnisse verändert.
Aus all diesen Gründen (und ein paar anderen) sind solche Tests Schall und Rauch.


> Der "Mikrobenchmark" hat nämlich einen für meine Zwecke ernsten Hintergrund


Nennst du uns selbigen?


----------



## Gast (13. Dez 2007)

Ja, für eine Optimierungsaufgabe möchte / muss ich alle Kombinationen "brute force" ausrechnen lassen und das Optimum finden. Ich benötige jedoch alle paar (3-5) Sekunden ein aktuelles Ergebnis.
Ich muß das Problem wohl partitionieren und auf mehrere Threads verteilen in der Hoffnung, diese werden schön gleichverteilt auf einem Multi-Core System abgearbeitet.

Toll wäre natürlich eine Einstellung, bei der das Programm von mir aus 30 Sekunden lädt (weil er da nur natives Kompilat erzeugt) und dann richtig durchstartet.

Es ist halt komisch und ungewohnt für jemanden aus der Delphi, C, ASM-Ecke, dass ein Programmteil mit 1 Mrd. Loops relativ gesehen *viel* schneller läuft als einer mit 10 Mrd. Loops. 

Schade dass es in Java keine Interpreter-Anweisungen gibt wie:

<gib hier alles>
for(i=...)
</gib hier alles>


----------



## Wildcard (13. Dez 2007)

Das erklärt nicht wozu die Messung nutzen soll.
Meinst du so austesten zu können nach wie vielen Iterationen 3-5 Sekunden verstrichen sind und du Rückmeldung  geben solltest?
Das funktioniert weder bei C noch Delphi noch ASM.


----------



## Gast (13. Dez 2007)

Nein, ich brauche binnen 3-5 Sekunden ein Ergebnis (eine Antwort / eine Entscheidung). Die Berechnung (Abklappern in einer for-Schleife) dauert aber z.B. in Java 40 Sekunden, in Delphi unoptimiert nur 6 Sekunden. Somit habe ich ein Problem bei Java und hoffte die 40-Javasekunden drücken zu können, z.B. durch Aufklärung der oben beschriebenen Anomalie: 

Laufzeit ist ist überproportional zu Iterationsanzahl bei einem linearen Problem (?)

Das hätte mich schonmal in die richtige Richtung gebracht, immerhin Faktor 2, wenn Java "im großen" genauso schnell arbeiten würde wie "im kleinen", denn eigentlich gefällt mir Java und Netbeans ganz gut, und: Es läuft offenbar auch unter Linux stabil, was man von z.B. FreePascal (als Delphi Ersatz) meiner Meinung nach überhaupt nicht sagen kann.


----------



## Wildcard (13. Dez 2007)

Gast hat gesagt.:
			
		

> wenn Java "im großen" genauso schnell arbeiten würde wie "im kleinen",


Nun ja, eigentlich läuft Java "im großen" nahezu genaus schnell wie nativ kompilierte Sprachen, nur eben im kleinen nicht immer.


> in Delphi unoptimiert nur 6 Sekunden


Ist der Code tatsächlich identisch? Der Unterschied sollte kleiner sein.
Ich gebe dir noch einen kleinen Tipp auf den Weg:
Gib dem JIT die Zeit zum Optimieren.
Wenn du die Berechnung in eine Methode auslagerst, welche du ein paar mal aufrufst, dann wird sie optimiert.
Bei mir ändert sich beim dritten Durchlauf die Zeit von 105 Sekunden auf 28.
Die Code Analyse im Hintergrund und das neu kompilieren gehen nunmal auf kosten der Laufzeit.
Die VM ist wie ein Auto, erst warmlaufen  :wink:

PS:
Wie lange dauert die oben aufgeführte Rechnung mit Delphi?
Der Code in beiden Sprachen für die Berechnung um die es eigentlich geht wäre auch interesant.


----------



## happy_robot (14. Dez 2007)

läuft bei mir unter kernel 2.6 und jdk 1.5_13 "quasi-linear".

kann es vielleicht sein daß du da irgendwelches debug-zeugs an hast und evtl. die überläufe zu den grossen unterschieden führen?


----------



## Marco13 (14. Dez 2007)

Bei mir mit WinXP und Java 1.6

Start!
Hello World: 1410065408 time=29958
Code: 1861874176

Start!
Hello World: 1000000000 time=2794
Code: -243309312

Was macht denn folgendes Programm bei dir

```
public class looptest
{
    public static void main (String argv[])
    {
        for (int n=1; n<5; n++)
        {
            test(n);
        }
    }

    public static void test(int n)
    {
      int i, j, k , l, m;
      long t;

      System.out.println("Start "+n);

      t=System.currentTimeMillis();

      j=0; k=0; l=0;

      for(m=0;m<n;m++)    //DER KNACKPUNKT
      for(i=0;i<1000000000;i++)
         {
          j++;
          k+=l*j+i;
          k++;
         }

      t=System.currentTimeMillis()-t;

      System.out.println("Hello World: "+j+" time="+t+" Code: "+k);
    }

}
```


----------



## bronks (14. Dez 2007)

Marco13 hat gesagt.:
			
		

> Bei mir mit WinXP und Java 1.6
> 
> Start!
> Hello World: 1410065408 time=29958
> ...


Jetzt schnallt euch mal an:


Ergebnis mit Java6

Start 1
Hello World: 1000000000 time=5016 Code: -243309312
Start 2
Hello World: 2000000000 time=9922 Code: -486618624
Start 3
Hello World: -1294967296 time=6734 Code: -729927936
Start 4
Hello World: -294967296 time=8906 Code: -973237248



Ergebnis mit Java5

Start 1
Hello World: 1000000000 time=6296 Code: -243309312
Start 2
Hello World: 2000000000 time=12391 Code: -486618624
Start 3
Hello World: -1294967296 time=18625 Code: -729927936
Start 4
Hello World: -294967296 time=24859 Code: -973237248


Ich habe das Programm je mehrmals laufen lassen.


----------



## Marco13 (14. Dez 2007)

Jo, da schlägt der JIT (wie Wildcard es beschrieben hatte) eben voll zu - nach dem 2. Durchlauf wird die Innere Schleife gerade mal mehr als doppelt so schnell abgearbeitet... Viel interessanter ist (eine Möglichkeit, die vielleicht den Threadersteller auch interessieren könnte, nämlich) das hier

*jdk1.5.0*\bin\java looptest
Start 1 Hello World: 1000000000  time=3484 Code: -243309312
Start 2 Hello World: 2000000000  time=7219 Code: -486618624
Start 3 Hello World: -1294967296 time=10469 Code: -729927936
Start 4 Hello World: -294967296  time=13953 Code: -973237248

*jdk1.5.0*\bin\java *-server* looptest
Start 1 Hello World: 1000000000  time=2562 Code: -243309312
Start 2 Hello World: 2000000000  time=5406 Code: -486618624
Start 3 Hello World: -1294967296 time=891 Code: -729927936
Start 4 Hello World: -294967296  time=1203 Code: -973237248

*jdk1.6.0_01*\bin\java looptest
Start 1 Hello World: 1000000000  time=2860 Code: -243309312
Start 2 Hello World: 2000000000  time=5703 Code: -486618624
Start 3 Hello World: -1294967296 time=4265 Code: -729927936
Start 4 Hello World: -294967296  time=5657 Code: -973237248

*jdk1.6.0_01*\bin\java *-server* looptest
Start 1 Hello World: 1000000000  time=3750 Code: -243309312
Start 2 Hello World: 2000000000  time=7782 Code: -486618624
Start 3 Hello World: -1294967296 time=890 Code: -729927936
Start 4 Hello World: -294967296  time=1204 Code: -973237248


----------



## Wildcard (14. Dez 2007)

Ich bin ganz froh das die Server VM in absehbarer Zeit die Client VM ersetzen soll...


----------



## semi (16. Dez 2007)

Wildcard hat gesagt.:
			
		

> Ich bin ganz froh das die Server VM in absehbarer Zeit die Client VM ersetzen soll...


Bei der x64 VM ist es bereits der Fall.  Ziemlich blöd ist es aber, wenn irgendwelche Java-Software 
den -client Parameter direkt verwendet.


----------

