1

最後の変更を行った後、コードが非常に遅くなりました。検索タスクには、2 ～ 3 秒ではなく 102 秒かかります。

profile制限機能を見つけるためにクラスを使用してみましたが、出力は次のとおりです。

>>> import WebParser
>>>
>>> w = WebParser.LinksGrabber
>>>
>>> import cProfile
>>> cProfile.run("w.search('nicki minaj', 15)")
         50326 function calls in 102.745 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000  102.745  102.745 <string>:1(<module>)
        6    0.000    0.000    0.000    0.000 Config.py:110(__getattr__)
        1    0.000    0.000  102.745  102.745 LinksGrabber.py:427(search)
        5    0.000    0.000    0.002    0.000 Queue.py:107(put)
      911    0.040    0.000  102.726    0.113 Queue.py:150(get)
       ..................................
      }
     6836    0.022    0.000    0.022    0.000 {min}
      917    0.009    0.000    0.009    0.000 {thread.allocate_lock}
        3    0.000    0.000    0.000    0.000 {thread.get_ident}
        3    0.000    0.000    0.000    0.000 {thread.start_new_thread}
    6835  100.458    0.015  100.458    0.015 {time.sleep}
    11346    0.035    0.000    0.035    0.000 {time.time}

time.sleepコードが を待っていることを示していますが、クラス100.458sでコード部分が見つかりません。WebParser.LinksGrabber

profile遅いコード部分に関する詳細情報を取得するにはどうすればよいですか?

4

1 に答える 1

2

プロファイリングする必要があるプログラムに追加するボイラープレート コードがあり、PROFILE変数をTrueor False...に変更することで簡単に有効または無効にできます。

#!/usr/bin/env python

# Should we profile the code?
PROFILE = True

# What proportion of the profile data should we keep?
PROFILE_LIMIT = 0.5         # 50%

# Where to store the raw profile data
PROFILE_DAT = 'profile.dat'

# Where to store the formatted profile data
PROFILE_TXT = 'profile.txt'


# Main code starts here
import time

def do_something():
    for i in range(5):
        time.sleep(0.1)

def do_something_else():
    for i in range(10):
        time.sleep(0.1)

def main():
    do_something()
    do_something_else()


if __name__ == '__main__':

    if PROFILE:
        import os, cProfile, pstats
        cProfile.runctx('main()', globals(), locals(), PROFILE_DAT)
        f = open(PROFILE_TXT, 'wb')
        for sort_key in 'time', 'cumulative':
            stats = pstats.Stats(PROFILE_DAT, stream=f)
            stats.sort_stats(sort_key)
            stats.print_stats(PROFILE_LIMIT)
            stats.strip_dirs()
            stats.sort_stats(sort_key)
            if sort_key == 'time':
                stats.print_callers(PROFILE_LIMIT)
            else:
                stats.print_callees(PROFILE_LIMIT)
        f.close()
        os.unlink(PROFILE_DAT)

    else:
        main()

profile.txt...これにより、...を含むテキスト ファイルが作成されます。

  1. 最も遅い関数 (内部的に) とそれらが呼び出された場所
  2. 最も遅い関数 (累積的に) とそれらが呼び出すもの

…こんな感じ…

[...]

   Ordered by: internal time
   List reduced from 7 to 4 due to restriction <0.5>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       15    1.627    0.108    1.627    0.108 {time.sleep}
        1    0.000    0.000    1.092    1.092 foo.py:23(do_something_else)
        1    0.000    0.000    0.536    0.536 foo.py:19(do_something)
        1    0.000    0.000    1.628    1.628 foo.py:27(main)


[...]

Function                      was called by...
                                  ncalls  tottime  cumtime
{time.sleep}                  <-       5    0.535    0.535  foo.py:19(do_something)
                                      10    1.092    1.092  foo.py:23(do_something_else)
foo.py:23(do_something_else)  <-       1    0.000    1.092  foo.py:27(main)
foo.py:19(do_something)       <-       1    0.000    0.536  foo.py:27(main)
foo.py:27(main)               <-       1    0.000    1.628  <string>:1(<module>)


[...]

   Ordered by: cumulative time
   List reduced from 7 to 4 due to restriction <0.5>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    1.628    1.628 <string>:1(<module>)
        1    0.000    0.000    1.628    1.628 foo.py:27(main)
       15    1.627    0.108    1.627    0.108 {time.sleep}
        1    0.000    0.000    1.092    1.092 foo.py:23(do_something_else)


[...]

Function                      called...
                                  ncalls  tottime  cumtime
<string>:1(<module>)          ->       1    0.000    1.628  foo.py:27(main)
foo.py:27(main)               ->       1    0.000    0.536  foo.py:19(do_something)
                                       1    0.000    1.092  foo.py:23(do_something_else)
{time.sleep}                  ->
foo.py:23(do_something_else)  ->       1    0.000    0.000  {range}
                                      10    1.092    1.092  {time.sleep}

...コードのどこを改善する必要があるかを突き止めるには、通常これで十分です。

于 2013-06-02T14:01:50.450 に答える