Analysieren von Routinen

Mit dem Kommando
     analyze routine
erhält man drei Tabellen, die wir uns an unserem Beispielprogramm LINALG in der Version 2.1 und der Optimierungsstufe -O2 ansehen wollen:
Routine Performance Analysis .     
(sorted by CPU time (less children)) .     
  CPU Time .CPU Time Times .Routine    
  (less children) .(plus children) Called .Name    
  0 .627 57 .7% 0 .627 57 .7% 1 gaussj
  0 .188 17 .3% 0 .188 17 .3% 2 testmt
  0 .127 11 .7% 0 .127 11 .7% 101 lubksb
  0 .071 6 .5% 0 .071 6 .5% 1 ludcmp
  0 .038 3 .5% 0 .038 3 .5% 10100 drand_$n
  0 .029 2 .6% 0 .066 6 .1% 1 getmat
    .    .    .    .  .     .
    .    .    .    .  .     .
    .    .    .    .  .     .


Die erste Tabelle zeigt für jede überwachte Routine die CPU-Zeiten, die alle Aufrufe dieser Routine ohne bzw. mit von ihr aufgerufenen Unterroutinen verbraucht haben sowie die Zahl der Aufrufe. Sortiert wird nach der CPU-Zeit der Routine selbst. Neben eigenen Routinen werden auch alle Bibliotheksroutinen aufgeführt, im Beispiel etwa die Routine ``drand_$n'' zum Erzeugen von Zufallszahlen. Bei der Routine ``getmat'' sieht man deutlich den Unterschied der ersten beiden Spalten: In ``getmat'' wird die Funktion ``drand'' aufgerufen, die selbst wieder ``drand_$n'' aufruft, von der der größte Teil der CPU-Zeit von getmat incl. Unterprogrammen stammt.
Routine Performance Analysis .    .   
(sorted by CPU time (less children)) .    .   
CPU Time CPU Time   .    .   
(less children) (plus children)   .    .   
  .    .   
Min. Max. .Avg. .Min. .Max. .Avg. .Routine name  
0 .627 0 .627 0 .627 0 .627 0 .627 0 .627 gaussj
0 .092 0 .096 0 .094 0 .092 0 .096 0 .094 testmt
0 .813m 1 .830m 1 .259m 0 .813m 1 .830m 1 .259m lubksb
0 .071 0 .071 0 .071 0 .071 0 .071 0 .071 ludcmp
0 .003m 0 .021m 0 .003m 0 .003m 0 .021m 0 .003m drand_$n
0 .029 0 .029 0 .029 0 .066 0 .066 0 .066 getmat
  .    .    .    .    .    .   
  .    .    .    .    .    .   


Während die erste Tabelle summarische Informationen über alle Aufrufe einer Funktion enthält, kann man an der zweiten ablesen, wie sich die Zeiten bei mehrfachem Aufruf einer Routine verteilen. Dazu wird für jede Routine der kleinste, größte und der Durchschnittswert der CPU-Zeit eines Aufrufs angegeben, jeweils ohne bzw. mit von ihr aufgerufenen Unterprogrammen. So sieht man z.B., daß die Aufrufe für die Routine ``lubksb'' für verschiedene Eingabe-Parameter recht stark streuen und könnte dies möglicherweise benutzen, um für verschiedene Parameterwerte unterschiedliche Optimierungen zu finden.
                      Dynamic Call Graph
        (in topological order, cycles severed)

        .
        .
      f_exit:
        parents:  (spontaneous call)
        children: fclose[3] for$clos2[3]

      for$clos2:
        parents:  f_exit
        children: free[3] t_runc[2]
        .
        .
      MAIN_:
        parents:  main
        children: for$do_lio[2] for$s_wsle[1] ernorm[1] testmt[1] gaussj[1]
                  setvec[1] setmat[1] getvec[1] getmat[1]

      getmat:
        parents:  MAIN_
        children: drand_$n[10000]

      getvec:
        parents:  MAIN_
        children: drand_$n[100]

      drand_$n:
        parents:  getvec getmat
        .
        .
Nach einer Liste aller Routinen, die zum Profilen vorbereitet waren, aber nicht aufgerufen wurden (vor allem eine Menge von Bibliotheksfunktionen) folgt der ``dynamische Aufruf-Graph''. Ein Aufruf-Graph (``Call Graph'') ist eigentlich eine Graphik, die in Baumform darstellt, welche Routine von welcher aufgerufen wird. Man unterscheidet zwischen dem statischen und dem dynamischen Aufruf-Graphen. Ersterer kann aus dem Programmtext abgeleitet werden, letzterer dagegen wird erst durch einen Programmlauf bestimmt. Um sich den Unterschied klarzumachen, denke man sich eine Funktion, die nach einer IF-Bedingung aufgerufen wird: Der statische Graph enthält sie immer, der dynamische nur dann, wenn die Bedingung zur Laufzeit erfüllt war. Da jedoch der CXpa (noch ?) keine graphische Schnittstelle hat, wird der Graph in Form einer Liste ausgegeben: Von der Spitze ausgehend werden die Routinen mit allen von ihnen direkt aufgerufenen Unterroutinen aufgelistet. In Klammern wird jeweils angegeben, wie oft eine Routine aufgerufen wurde. Rekursionen, d.h. Schleifen im Graphen, werden bei der ersten beteiligten Routine mit ``start of cycle'' gekennzeichnet.

Im Beispiel kommen zunächst einige Start-Routinen, etwa f_exit, bis das eigentliche Hauptprogramm aufgerufen wird, das vom Fortran-Compiler immer ``MAIN_'' genannt wird. Man sieht auch, daß der Compiler die ``DRAND''-Funktion in einen Aufruf von ``drand_$n'' verwandelt hat.

previous    contents     next

Peter Junglas 18.10.1993