Seltsame Profiler-Ergebnisse

Question

Ich habe gerade versucht, ein relativ einfaches Java-Programm mit jvisualvm zu profilieren. Die Ergebnisse waren etwas seltsam: Eine kleine 4-Linien-Methode hat die meiste Eigenzeit, deutlich mehr als jede andere Methode!

public class Hub 
    public void clock() { 
     for (int i = 0; i < cogs.length; i++) { 
      cogs[i].clock(cnt, i, this); 
     } 
     cnt++; 
    } 
} 

Hinweis: cogs.length ist 8 in diesem Fall!

Das ist seltsam, da die Cog.clock-Methode erheblich größer ist! Die einzige plausible Erklärung, die ich tun konnte, ist die Tatsache, dass die meisten (in diesem Fall 6 von 8) Cog Objekte in einem „gestoppt“ Zustand sein wird, die sich wie gefangen ist:

public class Cog 
    public void clock(int cnt, int cogid, Hub hub) { 
     if (state == State.STOP) 
      return; 
     //long code goes here 
    } 
} 

Aber das shouldn‘ Ich habe SO große Wirkung! Hier ist ein Bild von Beweis:

Answer 1

Profilieren beeinflusst die Laufzeit des Codes, weil sie Instrumente (modifiziert) es. Sie haben 12_000_000 Aufrufe in 9_000 ms, das sind etwa 750 Nanosekunden pro Aufruf, und das ist nach der Instrumentierung langsamer, also ohne Instrumentierung wäre das wahrscheinlich noch weniger. Zu solchen Zeiten pro Aufruf würde ich von einem Profiler nichts vernünftiges erwarten und würde seine Ergebnisse nicht für verschiedene Methoden vergleichen, es könnte gut sein, dass Methoden mit mehr Aufrufen höhere Punktzahl bekommen als solche mit weniger (wenn die meisten Ihrer Aufrufe sind nur Status prüfen und beenden). Sie könnten versuchen, VisualVM-Sampler zu verwenden, aber ich bin mir nicht sicher, ob es genau genug ist. Sie könnten versuchen, Zeiten selbst zu messen (mit System.nanoTime()), aber selbst das garantiert nicht die Genauigkeit von unter einer Mikrosekunde.