Ich habe ein kleines Paket erstellt mit dem man sehr einfach Funktionen profilen kann. Man kann sehr schnell erkennen, wie oft Funktionen durchlaufen werden und wie viel Zeit dafür benötigt wird. Eine feine Sache um seinen Code zu optimieren Verwendet wird der hotshot Profiler.
Als Beispiel möchte ich wissen was in der Funktion buildEpgEntry() meines Plugins vor sich geht. Zunächst muss ich dazu einen Import machen:
Außerdem setze ich einen Funktionsdekorator für meine Funktion buildEpgEntry():
@hotshotit
def buildEpgEntry(self, ignoreMe, eventid, sRef, begin, duration, title, short, desc):
Anschliessend starte ich mein Plugin und sorge dafür, daß die gewünschte Funktion natürlich auch mal aufgerufen wird. Dadurch wird eine Datei /tmp/Funktionsname.prof (also /tmp/buildEpgEntry.prof) angelegt.
Zum Schluß gehe ich mit telnet auf meine Box und lasse mir das Ergebnis anzeigen (Aufruf ohne die Dateiendung .prof):
Hier das Ergebnis:
root@bastelbox:~# profistats.sh buildEpgEntry
2346 function calls in 0.263 CPU seconds
Ordered by: internal time, call count
ncalls tottime percall cumtime percall filename:lineno(function)
34 0.184 0.005 0.263 0.008 EpgCenterList.py:179(buildEpgEntry)
1581 0.030 0.000 0.030 0.000 config.py:1567(__getattr__)
34 0.027 0.001 0.027 0.001 LoadPixmap.py:5(LoadPixmap)
17 0.006 0.000 0.009 0.001 HelperFunctions.py:255(findPicon)
34 0.005 0.000 0.013 0.000 HelperFunctions.py:232(getPiconFilename)
306 0.003 0.000 0.003 0.000 config.py:65(getValue)
221 0.002 0.000 0.002 0.000 config.py:307(getValue)
34 0.002 0.000 0.043 0.001 HelperFunctions.py:252(getPicon)
17 0.002 0.000 0.002 0.000 Directories.py:181(fileExists)
34 0.001 0.000 0.001 0.000 EpgCenterList.py:736(getTimerPixmapsForEntry)
34 0.001 0.000 0.001 0.000 HelperFunctions.py:379(updateEntry)
0 0.000 0.000 profile:0(profiler)
Alles anzeigen
Die Bedeutung der einzelnen Spalten:
ZitatAlles anzeigen
ncalls
for the number of calls,
tottime
for the total time spent in the given function (and excluding time made in calls to sub-functions),
percall
is the quotient of tottime divided by ncalls
cumtime
is the total time spent in this and all subfunctions (from invocation till exit). This figure is accurate even for recursive functions.
percall
is the quotient of cumtime divided by primitive calls
filename:lineno(function)
provides the respective data of each function
Dieses Paket basiert auf code von Trent Mick und befindet sich im Anhang