Warum ist diese Methode ein Hot Spot?

Question

Ich schreibe eine (einfache!) Lineare Algebra-Bibliothek. Bei der Implementierung von matrix multiplication eine VisualVM Leistung Probe wird mir zu sagen, dass der Algorithmus 85% seiner Zeit („self Zeit“, speziell) in dem folgende Verfahren verbringt, wenn große Matrizen multiplizieren (5k x 120k):

public double next() { 
    double result; 

    if(hasNext()) 
     result = vis[i++].next(); 
    else 
     throw new IllegalStateException("No next value"); 

    return result; 
} 

Ohne zu sehr ins Detail zu gehen (sorry, ich kann nicht mehr Code teilen), ist diese Methode die next() Methode eines "Iterators" für die Matrix. (Sie können sich die Klasse vorstellen, in der diese Methode als Zeileniterator aus einzelnen Spalteniteratoren lebt, die in vis gespeichert sind.) Es überrascht mich nicht, dass diese Methode viel aufgerufen wird, da sie ein Iterator ist, aber ich bin überrascht, dass das Programm eine Menge Zeit in diese Methode verbringt. Diese Methode macht nicht viel, also warum verbringt sie ihre Zeit hier?

Hier sind die spezifischen Fragen Ich frage:

1. Gibt es eine „Gotcha“ von VisualVM Ich schlage? Könnte das JIT zum Beispiel VisualVM in irgendeiner Weise verwirren, was dazu führt, dass VisualVM die Zeit der falschen Methode zuordnet?
2. Warum sollte das Programm hier seine Zeit verbringen? Die Methode macht einfach nicht viel. Insbesondere glaube ich nicht, dass Cache-Effekte dieses Problem erklären, da das Array vis viel kleiner ist als die Daten der Matrizen, die multipliziert werden.

Im Fall ist es sinnvoll, hier ist ein jad Demontage des Verfahrens ich oben eingefügt: für Ihre Hilfe Jungs

public double next() 
{ 
    double result; 
    if(hasNext()) 
//* 0 0:aload_0   
//* 1 1:invokevirtual #88 <Method boolean hasNext()> 
//* 2 4:ifeq   32 
     result = vis[i++].next(); 
// 3 7:aload_0   
// 4 8:getfield  #42 <Field VectorIterator[] vis> 
// 5 11:aload_0   
// 6 12:dup    
// 7 13:getfield  #28 <Field int i> 
// 8 16:dup_x1   
// 9 17:iconst_1   
// 10 18:iadd    
// 11 19:putfield  #28 <Field int i> 
// 12 22:aaload   
// 13 23:invokeinterface #72 <Method double VectorIterator.next()> 
// 14 28:dstore_1   
    else 
//* 15 29:goto   42 
     throw new IllegalStateException("No next value"); 
// 16 32:new    #89 <Class IllegalStateException> 
// 17 35:dup    
// 18 36:ldc1   #91 <String "No next value"> 
// 19 38:invokespecial #93 <Method void IllegalStateException(String)> 
// 20 41:athrow   
    return result; 
// 21 42:dload_1   
// 22 43:dreturn   
} 

Vielen Dank im Voraus!

Answer 1

Ich fand heraus, dass diese Methode wie ein Hotspot aussah, weil VisualVM angewiesen wurde, Methoden aus der JRE in seiner Profilerstellung zu ignorieren. Die Zeit, die in diesen "ignorierten" Methoden verbracht wurde, wurde (anscheinend) in die Eigenzeit des obersten nicht ignorierten Eintrags des Aufrufstapels gerollt.

Unten ist der Einstellungsbildschirm in VisualVM, einschließlich der Einstellung "Pakete nicht profilieren", die die Daten falsch gemacht hat. Um die "Klassen ignorieren" -Einstellungen anzupassen, müssen Sie (1) das Kontrollkästchen "Einstellungen" rot markieren und dann (2) die blau hervorgehobene Klasseneinstellung anpassen.

Je nachdem, was Sie tun, macht es wahrscheinlich Sinn zumindest nicht die java.* und javax.* Pakete zu ignorieren.

Answer 2

Ich kenne VisualVM nicht aus Erfahrung.

Zuerst ermitteln, ob es den Bytecode instrumentiert, um Statistiken zu sammeln. Wenn ja, dann suchen Sie nicht weiter - das Instrumentieren einer kurzen Methode überlagert immer die eigene Zeit (die Messung der Zeit und die Erhöhung des Statistikzählers kostet mehr Zeit als die Methode selbst).

Aber es ist immer möglich, dass der Iterator mehr Zeit als die Berechnung selbst verbraucht. Stellen Sie sich nur eine Matrix zusammen. Das Hinzufügen eines Gleitkommawerts zu einer lokalen Summenvariablen kostet viel weniger Zeit als das Aufrufen einer Methode, das Überprüfen einer Invariante und schließlich den Zugriff auf das Array.

Answer 3

Vergessen Sie den Profiler. Pausiere das verdammte Ding ein paar Mal und untersuche den Stapel. Wenn 85% der Zeit in diese Routine gehen, sind die Chancen 85% bei jeder Pause, die Sie genau sehen werden, wo es in dieser Routine ist, und genau, woher es kommt. Sie können sogar sehen, wo es bei der Multiplikation der Matrizen ist. Tausende von Proben werden Ihnen das nicht sagen.

Mein eigenes Gefühl ist, dass diese Funktion aufrufen, dann hasNext tun, dann Next auf jedes einzelne Element zu tun viel langsamer als i++ sein wird.