私の Python スクリプトはどこに時間を費やしているのでしょうか?私の cprofile / pstats トレースに「時間の欠落」はありますか?
https://stackoverflow.com/questions/2780294
-
03-10-2019 - |
italiano
english
français
española
中国
日本の
العربية
Deutsch
한국어
Português
Russian質問
長時間実行される Python スクリプトをプロファイリングしようとしています。スクリプトは、ラスター GIS データ セットに対して、 gdalモジュール. 。スクリプトは現在 3 つのファイルを使用しています。メイン スクリプトは、ラスター ピクセルをループする find_pixel_pairs.py, 、単純なキャッシュ lrucache.py そしていくつかのその他のクラス utils.py. 。中程度のサイズのデータセットでコードをプロファイリングしました。 pstats 戻り値：
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__)
上の 2 つの呼び出しには、メイン ループ、つまり分析全体が含まれています。残りのコールの合計は、11644 秒のうち 625 秒未満になります。残りの 11,000 秒はどこに費やされるのでしょうか?それはすべてメインループ内にありますか? find_pixel_pairs.py?その場合、コードのどの行に最も時間がかかっているかを確認できますか?
解決
ほとんどの時間が phes の 49 行目の関数 find_pixel_pairs.py. 。もっと知りたいなら別れる必要がある phes さらにサブ関数に分割し、再プロファイルします。
他のヒント
機能や測定のことは忘れてください。 このテクニックを使用してください。 デバッグモードで実行し、Ctrl+Cを数回押すだけです。コールスタックには、コードのどの行が時間の原因となっているかが正確に表示されます。
追加した：たとえば、10回一時停止します。EOL が言うように、11000 秒のうち 10400 秒が直接に費やされている場合、 phes, 、そのうち約 9 回の一時停止で停止します。 すぐそこに。一方、大部分の時間を以下から呼び出されるサブルーチンに費やしている場合は、 phes, そうすると、そのサブルーチン内でそれがどこにあるかがわかるだけでなく、それを呼び出している行 (時間なども担当する) がコール スタック上に表示されます。
で過ごした時間は、 コードの実行 各関数またはメソッドの内容は、 tottime カラム。の cumtime 方法は tottime+呼び出された関数に費やされた時間。
リストでは、探している 11,000 秒が、 phes 機能そのもの。所要時間はわずか約 600 秒です。
したがって、時間のかかるものを見つけたいとします。 phes, ~unutbu が示唆したように、サブ関数に分割して再プロファイリングします。
ボトルネックの可能性を特定した場合は、 phes の関数/メソッド find_pixel_pairs.py, 、使用できます line_profiler このような行ごとの実行プロファイルのパフォーマンス数値を取得するには（別の質問からコピーしました） ここ):
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))]
この情報を使用して、次のことを行います。 ない 壊す必要がある phes どの行の実行時間が最も長いかを正確に確認できるため、複数のサブ関数に分割できます。
スクリプトの実行時間が長いとのことなので、使用することをお勧めします line_profiler プロファイリングではオーバーヘッドが追加されますが、ライン プロファイリングではさらにオーバーヘッドが追加される可能性があるため、メソッドの数はできる限り制限します。
