Python Profiling

Allgemein

• Das Profiling dient dazu, Bottlenecks im Code zu finden.
• Anhand der Profiling-Daten kann leichter bestimmt werden, an welchen Stellen optimiert werden muss, um dann mit einem genaueren Tool wie z.B.Timeit Optimierungen zu vergleichen.
  • Siehe dazu den folgenden Auszug aus der profile.py Dokumentation:

Call count statistics can be used to identify bugs in code (surprising counts), and to identify possible inline-expansion points (high call counts). Internal time statistics can be used to identify “hot loops” that should be carefully optimized. Cumulative time statistics should be used to identify high level errors in the selection of algorithms.

Innerhalb von PLANTA

• Der Profiler kann messen, welche Python-Funktionen ausgeführt werden, wenn mit einem Feld interagiert wird.
• Wurden die Menüpunkte R39 Gesamt (CU) dem Benutzer zugeordnet und das DI Customizerrechte für den Benutzer aktiviert, so ist die Funktion im Menü unter Tools oder über den Shortcut F10 zu erreichen.

Anwendung

• Klick auf ein Eingabefeld, um den Fokus auf dieses zu setzen.
• F10 betätigen
• Je nach DF-Verhalten des Felds wird nun entweder das Profiling gestartet oder eine Dialogmeldung angezeigt, die nach einer Eingabe verlangt.

Feld mit DF-Verhalten i

• Wird nach einer Eingabe verlangt, wird analysiert, was passiert, wenn der eingegebene Wert in das Feld eingetragen wird.
• Bei Feldern, die nur einen Klick benötigen, wie z.B. Buttons oder Links, wird einfach der Klick simuliert.
• Nachdem das Profiling abgeschlossen wurde, erscheint erneut eine Dialogmeldung, die einem mehrere Optionen bietet, das Ergebnis des Profilings auszuwerten.

Sofortanalyse

• Die Sofortanalyse bietet einem Customizer ein schnelles Interface, um problematische Code-Stellen zu analysieren.
• Für komplexere Probleme bietet es sich an, bei jeder Version des Codes eine Profile-Datei abzuspeichern und die Ergebnisse in einem externen Tool zu analysieren (z.B. in RunSnakeRun oder mit dem Standard-Python-Modul).

• Damit die Messagebox nicht zu umfangreich wird, ist die Anzahl der angezeigten Zeilen pro Anzeigemodus wie folgt limitiert:

• Die Messagebox gliedert sich wie folgt:

• Die Spalten umschreiben Folgendes:

• Die verschiedenen Ansichten:

Beispiel

• Folgendes Makro wurde profiled:

from ppms import ppms

projects = [item for sublist in ppms.db_select("SELECT DI001001 FROM DT461") for item in sublist]

for project in projects:
    project_rec = ppms.search_record(461, [project], [1001], True)

• Ein Auszug aus dem Ergebnis, sortiert nach Call Count:

ncalls  tottime  percall  cumtime  percall 
      209    0.573    0.003    0.573    0.003 {built-in method search_record}
       11    0.000    0.000    0.000    0.000 ppms_.
        2    0.007    0.004    0.007    0.004 {built-in method db_select}

• Es ist zu sehen, dass search_record 209 aufgerufen wurde und damit 0.573 Sekunden verbraucht wurden.
• db_select wurde zweimal aufgerufen, was hier seltsam erscheint, denn das Makro ruft db_select nur einmal auf.
• Durch Klick auf den Normal-Button kann in eine andere Ansicht gewechselt werden.

• Das gleiche Profile von der Perspektive Callers aus betrachtet:

Function                                   was called by...
                                               ncalls  tottime  cumtime
{built-in method search_record}            <-       4    0.003    0.003  MACRO_MOD_009ATM.py:1(<module>)
                                                  204    0.569    0.569  MACRO_MOD_009BQX.py:1(<module>)
                                                    1    0.000    0.000  ppms_cu.
{built-in method db_select}                <-       1    0.006    0.006  MACRO_MOD_009BQX.py:1(<module>)
                                                    1    0.001    0.001  ppms_cu.
ppms_cu.        <-       1    0.000    0.016  MACRO_MOD_009ATM.py:1(<module>)

• 009BQX ist das Makromodul.
• 009ATM ist das Makro hinter dem Button in 00855 Module, welches das ausgewählte Modul aufruft.

• Es ist zu sehen, dass db_select wirklich nur einmal von dem Modul aufgerufen wurde.
  • Das Makro, welches hinter dem Button zum Modulaufruf steckt, musste jedoch auch indirekt eine Datenbankabfrage absetzen, weil es die Methode get_global_setting aus ppms_cu verwendet.

Sonstiges

• Python-Modul
• Profiling-Beispiel