Wie kann ich Python-Code zeilenweise profilieren?

116

Ich habe cProfile verwendet, um meinen Code zu profilieren, und es hat großartig funktioniert. Ich benutze auch gprof2dot.py , um die Ergebnisse zu visualisieren (macht es etwas klarer).

CProfile (und die meisten anderen Python-Profiler, die ich bisher gesehen habe) scheinen jedoch nur auf der Ebene des Funktionsaufrufs zu profilieren. Dies führt zu Verwirrung, wenn bestimmte Funktionen von verschiedenen Orten aus aufgerufen werden. Ich habe keine Ahnung, ob Anruf Nr. 1 oder Anruf Nr. 2 die meiste Zeit in Anspruch nimmt. Dies wird noch schlimmer, wenn die betreffende Funktion sechs Ebenen tief ist und von sieben anderen Stellen aus aufgerufen wird.

Wie erhalte ich eine zeilenweise Profilerstellung?

An Stelle von:

function #12, total time: 2.0s

Ich würde gerne so etwas sehen:

function #12 (called from somefile.py:102) 0.5s
function #12 (called from main.py:12) 1.5s

cProfile zeigt zwar an, wie viel der Gesamtzeit an das übergeordnete Element "übertragen" wird, aber diese Verbindung geht wieder verloren, wenn Sie mehrere Ebenen und miteinander verbundene Anrufe haben.

Im Idealfall hätte ich gerne eine grafische Benutzeroberfläche, die die Daten analysiert und mir dann meine Quelldatei mit einer Gesamtzeit für jede Zeile anzeigt. Etwas wie das:

main.py:

a = 1 # 0.0s
result = func(a) # 0.4s
c = 1000 # 0.0s
result = func(c) # 5.0s

Dann könnte ich auf den zweiten "func (c)" - Anruf klicken, um zu sehen, was in diesem Anruf Zeit in Anspruch nimmt, getrennt vom "func (a)" - Anruf.

Ist das sinnvoll? Gibt es eine Profilbibliothek, die diese Art von Informationen sammelt? Gibt es ein großartiges Tool, das ich vermisst habe?

Raketenmonkeys
quelle
2
Ich vermute, dass Sie interessiert wären pstats.print_callers. Ein Beispiel ist hier .
Muhammad Alkarouri
Muhammad, das ist definitiv hilfreich! Zumindest behebt es ein Problem: Trennen von Funktionsaufrufen nach Herkunft. Ich denke, Joe Kingtons Antwort ist näher an meinem Ziel, aber print_callers () bringt mich definitiv auf halbem Weg dorthin. Vielen Dank!
Raketenmonkeys

Antworten:

120

Ich glaube, dafür ist Robert Kerns line_profiler gedacht. Über den Link:

File: pystone.py
Function: Proc2 at line 149
Total time: 0.606656 s

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
   149                                           @profile
   150                                           def Proc2(IntParIO):
   151     50000        82003      1.6     13.5      IntLoc = IntParIO + 10
   152     50000        63162      1.3     10.4      while 1:
   153     50000        69065      1.4     11.4          if Char1Glob == 'A':
   154     50000        66354      1.3     10.9              IntLoc = IntLoc - 1
   155     50000        67263      1.3     11.1              IntParIO = IntLoc - IntGlob
   156     50000        65494      1.3     10.8              EnumLoc = Ident1
   157     50000        68001      1.4     11.2          if EnumLoc == Ident1:
   158     50000        63739      1.3     10.5              break
   159     50000        61575      1.2     10.1      return IntParIO

Hoffentlich hilft das!

Joe Kington
quelle
10
Funktioniert line_profiler mit Python 3? Ich konnte keine Informationen darüber bekommen.
user1251007
3
line_profiler zeigt für mich keine Treffer und keine Zeit an. Kann mir jemand sagen warum? Und wie zu lösen?
I159
6
Hier ist der Dekorateur, den ich geschrieben habe: gist.github.com/kylegibson/6583590 . Wenn Sie Nosetests ausführen, müssen Sie die Option -s verwenden, damit stdout sofort gedruckt wird.
Kyle Gibson
5
Wie sieht das Python-Skript aus, das diese Ausgabe erzeugt? import line_profiler;und dann ?
Zhubarb
10
kann jemand zeigen, wie man diese Bibliothek tatsächlich benutzt? Die Readme-Datei lehrt, wie man installiert, und beantwortet verschiedene FAQs, erwähnt aber nicht, wie man es nach einer Pip-Installation verwendet.
cryanbhu
47

Sie können auch pprofile ( pypi ) verwenden. Wenn Sie die gesamte Ausführung profilieren möchten, ist keine Änderung des Quellcodes erforderlich. Sie können eine Teilmenge eines größeren Programms auch auf zwei Arten profilieren:

  • Schalten Sie die Profilerstellung um, wenn Sie einen bestimmten Punkt im Code erreichen, z.

    import pprofile
    profiler = pprofile.Profile()
    with profiler:
        some_code
    # Process profile content: generate a cachegrind file and send it to user.
    
    # You can also write the result to the console:
    profiler.print_stats()
    
    # Or to a file:
    profiler.dump_stats("/tmp/profiler_stats.txt")
  • Umschalten der Profilerstellung asynchron vom Aufrufstapel (erfordert eine Möglichkeit, diesen Code in einer betrachteten Anwendung auszulösen, z. B. einem Signalhandler oder einem verfügbaren Worker-Thread) mithilfe der statistischen Profilerstellung:

    import pprofile
    profiler = pprofile.StatisticalProfile()
    statistical_profiler_thread = pprofile.StatisticalThread(
        profiler=profiler,
    )
    with statistical_profiler_thread:
        sleep(n)
    # Likewise, process profile content

Das Ausgabeformat für Code-Annotationen ähnelt dem Zeilenprofiler:

$ pprofile --threads 0 demo/threads.py
Command line: ['demo/threads.py']
Total duration: 1.00573s
File: demo/threads.py
File duration: 1.00168s (99.60%)
Line #|      Hits|         Time| Time per hit|      %|Source code
------+----------+-------------+-------------+-------+-----------
     1|         2|  3.21865e-05|  1.60933e-05|  0.00%|import threading
     2|         1|  5.96046e-06|  5.96046e-06|  0.00%|import time
     3|         0|            0|            0|  0.00%|
     4|         2|   1.5974e-05|  7.98702e-06|  0.00%|def func():
     5|         1|      1.00111|      1.00111| 99.54%|  time.sleep(1)
     6|         0|            0|            0|  0.00%|
     7|         2|  2.00272e-05|  1.00136e-05|  0.00%|def func2():
     8|         1|  1.69277e-05|  1.69277e-05|  0.00%|  pass
     9|         0|            0|            0|  0.00%|
    10|         1|  1.81198e-05|  1.81198e-05|  0.00%|t1 = threading.Thread(target=func)
(call)|         1|  0.000610828|  0.000610828|  0.06%|# /usr/lib/python2.7/threading.py:436 __init__
    11|         1|  1.52588e-05|  1.52588e-05|  0.00%|t2 = threading.Thread(target=func)
(call)|         1|  0.000438929|  0.000438929|  0.04%|# /usr/lib/python2.7/threading.py:436 __init__
    12|         1|  4.79221e-05|  4.79221e-05|  0.00%|t1.start()
(call)|         1|  0.000843048|  0.000843048|  0.08%|# /usr/lib/python2.7/threading.py:485 start
    13|         1|  6.48499e-05|  6.48499e-05|  0.01%|t2.start()
(call)|         1|   0.00115609|   0.00115609|  0.11%|# /usr/lib/python2.7/threading.py:485 start
    14|         1|  0.000205994|  0.000205994|  0.02%|(func(), func2())
(call)|         1|      1.00112|      1.00112| 99.54%|# demo/threads.py:4 func
(call)|         1|  3.09944e-05|  3.09944e-05|  0.00%|# demo/threads.py:7 func2
    15|         1|  7.62939e-05|  7.62939e-05|  0.01%|t1.join()
(call)|         1|  0.000423908|  0.000423908|  0.04%|# /usr/lib/python2.7/threading.py:653 join
    16|         1|  5.26905e-05|  5.26905e-05|  0.01%|t2.join()
(call)|         1|  0.000320196|  0.000320196|  0.03%|# /usr/lib/python2.7/threading.py:653 join

Beachten Sie, dass pprofile, da es nicht auf Codeänderungen angewiesen ist, Modulanweisungen der obersten Ebene profilieren kann, wodurch die Programmstartzeit profiliert werden kann (wie lange es dauert, Module zu importieren, globale Elemente zu initialisieren, ...).

Es kann eine Cachegrind-formatierte Ausgabe generieren, sodass Sie kcachegrind verwenden können, um große Ergebnisse einfach zu durchsuchen.

Offenlegung: Ich bin ein Profilautor.

vpelletier
quelle
1
+1 Vielen Dank für Ihren Beitrag. Es sieht gut gemacht aus. Ich habe eine etwas andere Perspektive - die Messung der Inklusionszeit von Aussagen und Funktionen ist ein Ziel. Ein anderes Ziel ist es, herauszufinden, was getan werden kann, um den Code schneller zu machen. Der Unterschied wird schmerzlich offensichtlich, wenn der Code groß wird - wie 10 ^ 6 Codezeilen. Der Code kann viel Zeit verschwenden. Ich finde es so, dass ich eine kleine Anzahl sehr detaillierter Proben nehme und sie mit einem menschlichen Auge untersuche - nicht zusammenfassend. Das Problem wird durch den Zeitanteil aufgedeckt, den es verschwendet.
Mike Dunlavey
1
Sie haben Recht, ich habe die Verwendung von Profilen nicht erwähnt, wenn man eine kleinere Teilmenge profilieren möchte. Ich habe meinen Beitrag bearbeitet, um Beispiele dafür hinzuzufügen.
Vpelletier
3
Genau das habe ich gesucht: nicht aufdringlich und umfangreich.
egpbos
1
Nettes Tool, aber es läuft um ein Vielfaches langsamer als der ursprüngliche Code.
Rominf
4

Sie können Hilfe nehmen line_profiler für dieses Paket

1. Installieren Sie zuerst das Paket:

    pip install line_profiler

2. Laden Sie das Paket mit dem Befehl magic in Ihre Python- / Notebook-Umgebung

    %load_ext line_profiler

3. Wenn Sie die Codes für eine Funktion profilieren möchten,
gehen Sie wie folgt vor:

    %lprun -f demo_func demo_func(arg1, arg2)

Sie erhalten eine schöne formatierte Ausgabe mit allen Details, wenn Sie diese Schritte ausführen :)

Line #      Hits      Time    Per Hit   % Time  Line Contents
 1                                           def demo_func(a,b):
 2         1        248.0    248.0     64.8      print(a+b)
 3         1         40.0     40.0     10.4      print(a)
 4         1         94.0     94.0     24.5      print(a*b)
 5         1          1.0      1.0      0.3      return a/b
Sateesh
quelle
4

Nur um die oben erwähnte Antwort von @Joe Kington zu verbessern .

Verwenden Sie für Python 3.x line_profiler :


Installation:

pip install line_profiler

Verwendung:

Angenommen, Sie haben das Programm main.pyund darin Funktionen fun_a()und fun_b()möchten sich zeitlich profilieren. Sie müssen den Dekorator @profiledirekt vor den Funktionsdefinitionen verwenden. Zum Beispiel

@profile
def fun_a():
    #do something

@profile
def fun_b():
    #do something more

if __name__ == '__main__':
    fun_a()
    fun_b()

Das Programm kann durch Ausführen des Shell-Befehls profiliert werden:

$ kernprof -l -v main.py

Die Argumente können mit abgerufen werden $ kernprof -h

Usage: kernprof [-s setupfile] [-o output_file_path] scriptfile [arg] ...

Options:
  --version             show program's version number and exit
  -h, --help            show this help message and exit
  -l, --line-by-line    Use the line-by-line profiler from the line_profiler
                        module instead of Profile. Implies --builtin.
  -b, --builtin         Put 'profile' in the builtins. Use 'profile.enable()'
                        and 'profile.disable()' in your code to turn it on and
                        off, or '@profile' to decorate a single function, or
                        'with profile:' to profile a single section of code.
  -o OUTFILE, --outfile=OUTFILE
                        Save stats to <outfile>
  -s SETUP, --setup=SETUP
                        Code to execute before the code to profile
  -v, --view            View the results of the profile in addition to saving
                        it.

Die Ergebnisse werden auf der Konsole wie folgt gedruckt:

Total time: 17.6699 s
File: main.py
Function: fun_a at line 5

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    5                                           @profile
    6                                           def fun_a():
...

BEARBEITEN: Die Ergebnisse der Profiler können mit dem TAMPPA- Paket analysiert werden . Mit ihm können wir zeilenweise gewünschte Diagramme erhalten als Handlung

Pe Dro
quelle
1

PyVmMonitor verfügt über eine Live-Ansicht, die Ihnen dort weiterhelfen kann (Sie können eine Verbindung zu einem laufenden Programm herstellen und Statistiken daraus abrufen).

Siehe: http://www.pyvmmonitor.com/

Fabio Zadrozny
quelle