[gprof] Was bedeuten die Spalten?



  • Hallo,
    ich hab hier ein Programm, das ich mit grpof analysiert habe:

    Flat profile:
    
    Each sample counts as 0.01 seconds.
      %   cumulative   self              self     total           
     time   seconds   seconds    calls   s/call   s/call  name    
     44.82      0.56     0.56    97994     0.00     0.00  CFleet::SSE_Subtract(std::vector<int, alignment_allocator<int, 16> >&, unsigned long, int)
     18.41      0.79     0.23   701069     0.00     0.00  CFleet::GetShipAtPos(int, int*)
      8.80      0.90     0.11   701069     0.00     0.00  CShip::Fire(CShip*)
      8.00      1.00     0.10   701069     0.00     0.00  CFightSimulator::PlayerShoot(int, int, int)
      7.20      1.09     0.09   701069     0.00     0.00  CShield::AbsorbDamage(int*, CWeapon*)
      3.20      1.13     0.04   701089     0.00     0.00  CTimer::Stop()
      3.20      1.17     0.04    97994     0.00     0.00  CFleet::ClearShip(int)
      1.60      1.19     0.02   701089     0.00     0.00  CTimer::Restart()
      1.60      1.21     0.02   701069     0.00     0.00  mersenne_genrand_int32()
      1.60      1.23     0.02        1     0.02     1.23  CFightSimulator::Run()
      0.80      1.24     0.01        4     0.00     0.00  CFleet::AddShip(char const*, int)
      0.80      1.25     0.01                             _DPRINT(int, char*, ...)
      0.00      1.25     0.00  1500274     0.00     0.00  _DPRINTL(int, char*, ...)
    

    Mein Problem ist, dass ich die Spalten nicht so wirklich alle kapier. Die erste (% time) ist ja klar. die zweite (culmutativ seconds) auch (einfach die Summe von "self seconds" aller vorherigen Funktionen, wobei ich in der Angabe jetzt keinen großen Sinn sehe...). Die 3. Spalte "self seconds" würde ich ja auch kapieren. Allerdings gibts da ein kleines logisches Problem. "self seconds" ist ja die Zeit, die das Programm in der einen Funktion verbracht hat. Also müsste die summe aller self seconds die Ausführungszeit ergeben. Tut sie aber nicht: Mein Programm hat für die ausführung 20 Sekunden gebraucht, die Summe aller "self seconds" ist allerdings nur 1,25 Sekunden.
    Wie ist das zu erklären???





  • Die "self time" ist schon das was du denkst, also die Zeit die direkt in der Funktion verbraten wird, ohne die Zeit die in aufgerufenen Unterfunktionen verbraucht wird.

    Zu den 20 Sek. vs. 1,25 Sek.: das wird wohl daran liegen dass der Profiler einen ziemlichen Overhead hat, also Zeit die draufgeht beim Abspeichern von Anfangs-/Endzeit einer Funktion etc.
    Normalerweise rechnet das ein Profiler raus, zeigt also nur das an was nicht Overhead vom Profiler selbst ist. Dadurch ist die Summe aller "self time"s dann eben wesentlich kleiner als die tatsächliche Laufzeit.

    Wäre sonst auch ziemlich doof, da der Overhead normalerweise pro Funktionsaufruf konstant ist. D.h. Funktionen die sehr sehr schnell laufen ("return 1;") würden grob benachteiligt.


Anmelden zum Antworten