Wo ist mein Python-Skript viel Zeit? Gibt es „fehlende Zeit“ in meinem Cprofile / pstats Spur?
-
03-10-2019 - |
Frage
Ich versuche, eine lange laufenden Python-Skript zu profilieren. Das Skript hat einige räumliche Analyse auf Raster GIS Datensatz unter Verwendung der gdal Modul . Das Skript verwendet derzeit drei Dateien, die Haupt-Skript, das über die Raster Pixel genannt find_pixel_pairs.py
Schleifen, einem einfachen Cache in lrucache.py
und einige misc Klassen in utils.py
. Ich habe den Code auf einem moderaten Größe Dataset profiliert. pstats
kehrt:
p.sort_stats('cumulative').print_stats(20)
Thu May 6 19:16:50 2010 phes.profile
355483738 function calls in 11644.421 CPU seconds
Ordered by: cumulative time
List reduced from 86 to 20 due to restriction <20>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.008 0.008 11644.421 11644.421 <string>:1(<module>)
1 11064.926 11064.926 11644.413 11644.413 find_pixel_pairs.py:49(phes)
340135349 544.143 0.000 572.481 0.000 utils.py:173(extent_iterator)
8831020 18.492 0.000 18.492 0.000 {range}
231922 3.414 0.000 8.128 0.000 utils.py:152(get_block_in_bands)
142739 1.303 0.000 4.173 0.000 utils.py:97(search_extent_rect)
745181 1.936 0.000 2.500 0.000 find_pixel_pairs.py:40(is_no_data)
285478 1.801 0.000 2.271 0.000 utils.py:98(intify)
231922 1.198 0.000 2.013 0.000 utils.py:116(block_to_pixel_extent)
695766 1.990 0.000 1.990 0.000 lrucache.py:42(get)
1213166 1.265 0.000 1.265 0.000 {min}
1031737 1.034 0.000 1.034 0.000 {isinstance}
142740 0.563 0.000 0.909 0.000 utils.py:122(find_block_extent)
463844 0.611 0.000 0.611 0.000 utils.py:112(block_to_pixel_coord)
745274 0.565 0.000 0.565 0.000 {method 'append' of 'list' objects}
285478 0.346 0.000 0.346 0.000 {max}
285480 0.346 0.000 0.346 0.000 utils.py:109(pixel_coord_to_block_coord)
324 0.002 0.000 0.188 0.001 utils.py:27(__init__)
324 0.016 0.000 0.186 0.001 gdal.py:848(ReadAsArray)
1 0.000 0.000 0.160 0.160 utils.py:50(__init__)
Die beiden Top-Anrufe enthalten die Hauptschleife - den gesamten Analyis. Die übrigen Anrufe Summe auf weniger als 625 der 11.644 Sekunden. Wo sind die restlichen 11.000 Sekunden ausgegeben? Ist es in der Hauptschleife von find_pixel_pairs.py
? Wenn ja, kann ich herausfinden, welche Codezeilen nehmen die meiste Zeit?
Lösung
Sie haben Recht, dass die meiste Zeit in der phes
Funktion auf der Leitung 49 von find_pixel_pairs.py
ausgegeben wird. Um mehr zu erfahren, müssen Sie phes
in mehr Unterfunktionen aufzubrechen, und dann profilieren.
Andere Tipps
Vergessen Funktionen und Messen. Mit dieser Technik. führen sie es nur im Debug-Modus, und drücken sie Strg-C ein paar mal. Der Call-Stack zeigt Ihnen genau, welche Codezeilen sind für die Zeit verantwortlich.
Hinzugefügt: Zum Beispiel pausiert es 10-mal. Wenn, wie EOL sagt, 10.400 Sekunden aus 11000 direkt in phes
ausgegeben werden, dann auf etwa 9 diese Pausen, wird es aufhören genau dort .
Wenn auf der anderen Seite wird es einen großen Teil der Zeit in einem gewissen Unterprogramm von phes
genannt zu verbringen, dann werden Sie nicht nur sehen, wo es in diesem Unterprogramm ist, aber Sie werden die Linien sehen, dass es nennen, die auch für die verantwortlich sind die Zeit, und so weiter, bis der Call-Stack.
Die Zeit, in der Code-Ausführung jede Funktion oder Methode ist in der tottime
Spalte. Die cumtime
Methode ist tottime
+ Zeit in Funktionen ausgegeben genannt.
In Ihren Eintrag, sehen Sie, dass die 11.000 Sekunden, dass Sie suchen, sich direkt von der phes
Funktion ausgegeben werden. Was es nennt dauert nur etwa 600 Sekunden.
So wollen Sie finden, was Zeit in phes
nimmt, indem es Zerschlagung in Teilfunktionen und Reprofilierung, wie ~ unutbu vorgeschlagen.
Wenn Sie mögliche Engpässe in der phes
Funktion / Methode in find_pixel_pairs.py
identifiziert haben, können Sie line_profiler
verwenden können, wie diese Zeile-für-Zeile Ausführungsprofil Performance-Zahlen zu erhalten (von einer anderen Frage kopiert here ):
Timer unit: 1e-06 s
Total time: 9e-06 s
File: <ipython-input-4-dae73707787c>
Function: do_other_stuff at line 4
Line # Hits Time Per Hit % Time Line Contents
==============================================================
4 def do_other_stuff(numbers):
5 1 9 9.0 100.0 s = sum(numbers)
Total time: 0.000694 s
File: <ipython-input-4-dae73707787c>
Function: do_stuff at line 7
Line # Hits Time Per Hit % Time Line Contents
==============================================================
7 def do_stuff(numbers):
8 1 12 12.0 1.7 do_other_stuff(numbers)
9 1 208 208.0 30.0 l = [numbers[i]/43 for i in range(len(numbers))]
10 1 474 474.0 68.3 m = ['hello'+str(numbers[i]) for i in range(len(numbers))]
Mit diesen Informationen Sie tun nicht Notwendigkeit phes
bricht in mehrere Teilfunktionen, weil Sie genau sehen können, welche Linien die höchste Ausführungszeit haben.
Da Sie erwähnen, dass Ihr Skript lange läuft, würde ich mit line_profiler
auf als begrenzte Anzahl von Methoden wie möglich empfehlen, da während Profilierung zusätzliche Overhead hinzufügt, Linienprofilierung mehr hinzufügen können.