我的python脚本在哪里花费时间？我的cprofile / pstats跟踪中是否有“丢失时间”？

Question

我正在尝试分析一个长时间运行的python脚本。该脚本使用gdal module对栅格地理信息系统数据集进行一些空间分析。该脚本当前使用三个文件，主脚本循环光栅像素，名为find_pixel_pairs.py，lrucache.py中的一个简单缓存和utils.py中的一些misc类。我已经在一个中等大小的数据集上分析了代码。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__)

前两个调用包含主循环-整个分析。其余调用的总和不到11644秒中的625秒。剩下的11,000秒花在哪里了？它们都在find_pixel_pairs.py的主循环中吗？如果是这样的话，我能找出哪些代码行占用了大部分时间吗？

Answer 1

您说得对，大部分时间都花在了find_pixel_pairs.py的第49行的phes函数上。要了解更多信息，您需要将phes分解为更多的子函数，然后重新分析。

Answer 2

忘记函数和测量。Use this technique.只需在调试模式下运行它，然后按ctrl-C键几次。调用堆栈将准确地向您显示负责时间的代码行。

新增:例如，暂停10次。如果像EOL所说的那样，11000秒中有10400秒直接花在phes上，那么在这些暂停中大约有9秒，它就会到此为止。另一方面，如果它在从phes调用的某个子例程中花费了很大一部分时间，那么您不仅会看到它在该子例程中的位置，还会看到调用它的行，这些行也负责调用堆栈中的时间，等等。

Answer 3

执行每个函数或方法的代码所花费的时间在tottime列中。cumtime方法是调用函数所花费的tottime+时间。

在您的清单中，您可以看到您正在寻找的11,000秒被phes函数本身直接花费了。它所谓的只需要大约600秒。

因此，您想要通过将phes分解为子函数并重新分析来找出它需要花费的时间，就像~unutbu建议的那样。