Python-Profiling Neu ab DB 39.5.0

Allgemein

info Informationen
  • 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.
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.
ProfilerProfileField.PNG
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.
Button Funktion
Sofortanalyse Das Ergebnis direkt in einer MessageBox anzeigen
Datei generieren Das Ergebnis als Datei abspeichern
Abbrechen Das Ergebnis verwerfen

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).

note Details

  • Damit die Messagebox nicht zu umfangreich wird, ist die Anzahl der angezeigten Zeilen pro Anzeigemodus wie folgt limitiert:
Modus Begrenzung
Normal 25 Zeilen
Callers 15 Zeilen
Callees 15 Zeilen

  • Die Messagebox gliedert sich wie folgt:
ProfileDefaultMsg.png

Nummer Erklärung
1 Zeit der Analyse und Pfad, an dem die Profile-Datei liegt. Bei der Sofortanalyse befindet sich die Datei immer in einem temporären Ordner
2 Die Anzahl der Funktionsaufrufe mit Rekursion, ohne und die gesamte Dauer
3 Nach was wird sortiert und wieviel wird angezeigt
4 Die Profile-Tabelle
5, 6, 7, 8 Nach der entsprechenden Spalte sortieren
9 Zwischen den Ansichten Normal, Callers und Callees umschalten
10 Anzeige abbrechen und MessageBox schließen

  • Die Spalten umschreiben Folgendes:
Spalte Erklärung
ncalls Die Anzahl der Aufrufe und Anzahl ohne rekursive Aufrufe durch einen Slash getrennt
tottime Gesamte Zeit, die in dieser Funktion verbrachte wurde, ohne Aufrufe der Unterfunktionen
percall tottime/ncalls
cumtime Zeit, die innerhalb der Funktion von Aufruf bis Abschluss verbracht wurde, einschließlich aller Unterfunktionen
percall cumtime/ncalls
filename:lineno(function) Name der Datei: Zeilennummer (Funktionsname)
  • Die verschiedenen Ansichten:
Ansicht Bedeutung
Normal Zeigt Funktionsaufrufe mit Werten für die oben genannten Spalten
Callers Zeigt an, von was eine Funktion aufgerufen wurde sowie die ncalls, tottime und cumtime
Callees Zeigt an, welche Unterfunktionen von einer Funktion aufgerufen wurden sowie die gleichen Spalten wie die Ansicht Callers

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}

note Details

  • 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>)

warning Hinweise

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

note Details

  • 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

Topic attachments
I Attachment Action Size Date Who Comment
pngpng ProfileDefaultMsg.png manage 40.9 K 2012-07-17 - 12:00 JuliaSchwarz  
pngPNG ProfilerProfileField.PNG manage 7.5 K 2012-07-17 - 12:00 JuliaSchwarz  
Topic revision: r18 - 2017-06-19 - 14:17:06 - IrinaZieger








 
  • Suche in Topic-Namen

  • Suche in Topic-Inhalten