Programme zu schreiben macht Spaß, aber sie schnell zu machen kann eine Qual sein. Python-Programme sind da keine Ausnahme, aber die grundlegende Profiling-Toolchain ist eigentlich gar nicht so kompliziert zu benutzen. Hier möchte ich Ihnen zeigen, wie Sie Ihren Python-Code schnell profilieren und analysieren können, um herauszufinden, welchen Teil des Codes Sie optimieren sollten.
Das Profilieren eines Python-Programms ist eine dynamische Analyse, die die Ausführungszeit des Programms und aller Bestandteile misst. Das bedeutet, dass die Zeit gemessen wird, die in jeder der Funktionen verbracht wird. Dadurch erhalten Sie Daten darüber, wo Ihr Programm Zeit verbringt und in welchem Bereich es sich lohnen könnte, es zu optimieren.
Es ist eine sehr interessante Übung. Viele Leute konzentrieren sich auf lokale Optimierungen, wie z.B. die Frage, welche der Python-Funktionen range oder xrange schneller sein wird. Es stellt sich heraus, dass die Frage, welche Funktion schneller ist, in Ihrem Programm vielleicht nie eine Rolle spielt, und dass der Zeitgewinn durch eine der oben genannten Funktionen die Zeit nicht wert ist, die Sie für die Recherche oder die Diskussion mit Ihrem Kollegen aufwenden.
Der Versuch, ein Programm blind zu optimieren, ohne zu messen, wo es tatsächlich seine Zeit verbringt, ist eine nutzlose Übung. Es reicht nicht immer aus, nur seinem Bauchgefühl zu folgen.
Es gibt viele Arten der Profilerstellung, so wie es viele Dinge gibt, die man messen kann. In dieser Übung konzentrieren wir uns auf die CPU-Auslastung, d.h. die Zeit, die jede Funktion mit der Ausführung von Anweisungen verbringt. Natürlich könnten wir noch viele weitere Arten von Profilen und Optimierungen durchführen, wie z.B. Speicher-Profiling, das den von jedem Stück Code verbrauchten Speicher misst – etwas, worüber ich in The Hacker’s Guide to Python spreche.
cProfile
Seit Python 2.5 bietet Python ein C-Modul namens cProfile, das einen vernünftigen Overhead hat und einen ausreichenden Funktionsumfang bietet. Die grundlegende Verwendung ist:
Allerdings kann man damit auch ein Skript ausführen, was sich als praktisch erweist:
Dies gibt alle aufgerufenen Funktionen aus, mit der Zeit, die in jeder Funktion verbracht wurde, und der Anzahl der Aufrufe.
Fortgeschrittene Visualisierung mit KCacheGrind
Das Ausgabeformat ist zwar nützlich, aber sehr einfach und macht es nicht einfach, Wissen über komplette Programme zu erlangen. Für fortgeschrittene Visualisierung verwende ich KCacheGrind. Wenn Sie in den letzten Jahren mit C-Programmierung und -Profiling zu tun hatten, haben Sie es vielleicht benutzt, da es in erster Linie als Front-End für die von Valgrind erzeugten Call-Graphs gedacht ist.
Um es zu benutzen, müssen Sie eine cProfile-Ergebnisdatei erzeugen und sie dann in das KCacheGrind-Format konvertieren. Dazu verwende ich pyprof2calltree.
$ python -m cProfile -o myscript.cprof myscript.py$ pyprof2calltree -k -i myscript.cprofUnd das KCacheGrind-Fenster erscheint auf magische Weise!
Konkreter Fall: Carbonara-Optimierung
Ich war neugierig auf die Leistung von Carbonara, der kleinen Zeitreihenbibliothek, die ich für Gnocchi geschrieben habe. Ich beschloss, ein grundlegendes Profiling durchzuführen, um zu sehen, ob es eine offensichtliche Optimierungsmöglichkeit gibt.
Um ein Programm zu profilieren, muss man es ausführen. Aber wenn man das ganze Programm im Profiling-Modus laufen lässt, kann man eine Menge Daten generieren, die einen nicht interessieren und die das, was man zu verstehen versucht, nur verzerren. Da Gnocchi über Tausende von Unit-Tests und einige für Carbonara selbst verfügt, habe ich beschlossen, den von diesen Unit-Tests verwendeten Code zu profilieren, da er die grundlegenden Funktionen der Bibliothek gut widerspiegelt.
Bitte beachten Sie, dass dies eine gute Strategie für ein neugieriges und naives First-Pass-Profiling ist.
Es gibt keine Möglichkeit, sicherzustellen, dass die Hotspots, die Sie in den Unit-Tests sehen, die tatsächlichen Hotspots sind, die Sie in der Produktion antreffen werden. Daher ist ein Profiling unter Bedingungen und mit einem Szenario, das die Produktionsbedingungen nachahmt, oft eine Notwendigkeit, wenn Sie Ihre Programmoptimierung weiter vorantreiben und einen spürbaren und wertvollen Gewinn erzielen wollen.
Ich aktiviere cProfile mit der oben beschriebenen Methode und erstelle ein cProfile.Profile Objekt um meine Tests herum (ich habe damit begonnen, dies in testtools zu implementieren). Dann habe ich KCacheGrind wie oben beschrieben ausgeführt. Mit KCacheGrind habe ich die folgenden Zahlen generiert.
Der Test, den ich hier profiliert habe, heißt test_fetch und ist ziemlich einfach zu verstehen: Er legt Daten in ein Timeserie-Objekt und holt dann das aggregierte Ergebnis ab. Die obige Liste zeigt, dass 88 % der Ticks in set_values verbracht werden (44 Ticks über 50). Diese Funktion wird zum Einfügen von Werten in die Zeitreihe verwendet, nicht zum Abrufen der Werte. Das bedeutet, dass es sehr langsam ist, Daten einzufügen, und ziemlich schnell, sie tatsächlich abzurufen.
Wenn man den Rest der Liste liest, sieht man, dass sich mehrere Funktionen den Rest der Ticks teilen, update, _first_block_timestamp, _truncate, _resample, usw. Einige der Funktionen in der Liste sind nicht Teil von Carbonara, so dass es sinnlos ist, sie zu optimieren. Das einzige, was optimiert werden kann, ist manchmal die Anzahl der Aufrufe.
Das Aufrufdiagramm gibt mir etwas mehr Aufschluss darüber, was hier vor sich geht. Mit meinem Wissen über die Funktionsweise von Carbonara glaube ich nicht, dass der ganze Stapel auf der linken Seite für _first_block_timestamp viel Sinn macht. Diese Funktion soll den ersten Zeitstempel für ein Aggregat finden, z.B. mit einem Zeitstempel von 13:34:45 und einem Zeitraum von 5 Minuten sollte die Funktion 13:30:00 zurückgeben. Derzeit wird die Funktion resample von Pandas für eine Zeitreihe mit nur einem Element aufgerufen, aber das scheint sehr langsam zu sein. Tatsächlich macht diese Funktion derzeit 25 % der von set_values verbrauchten Zeit aus (11 Ticks auf 44).
Glücklicherweise habe ich kürzlich eine kleine Funktion namens _round_timestamp hinzugefügt, die genau das tut, was _first_block_timestamp braucht, ohne eine Pandas-Funktion aufzurufen, also keine resample. Also habe ich diese Funktion folgendermaßen umgeschrieben:
Und dann habe ich den gleichen Test erneut ausgeführt, um die Ausgabe von cProfile zu vergleichen.
Die Liste der Funktionen scheint dieses Mal ganz anders auszusehen. Die Anzahl der von set_values verbrauchten Zeit ist von 88 % auf 71 % gesunken.
Der Aufrufstapel für set_values zeigt das ziemlich gut: wir können die Funktion _first_block_timestamp nicht einmal sehen, da sie so schnell ist, dass sie völlig aus der Anzeige verschwunden ist. Sie wird jetzt vom Profiler als unbedeutend eingestuft.
Wir haben also den gesamten Prozess des Einfügens von Werten in Carbonara in wenigen Minuten um schöne 25 % beschleunigt. Nicht schlecht für einen ersten naiven Durchgang, oder?
Wenn Sie mehr wissen wollen, habe ich ein ganzes Kapitel über die Optimierung von Code in Scaling Python geschrieben. Schauen Sie es sich an!