如何调试一个永不停歇的代码？

Question

我有一段很大的代码，现在有些地方执行得太慢了。我也不知道具体是哪个地方。

这段代码没有报错，只是看起来一直在处理某些东西。

我想在一些函数周围加上计时器，看看哪个函数是问题所在。但我不太确定这样做是否合适，或者该怎么做。

我不能随便在代码的某些地方抛出异常，因为有很多循环会调用同样的函数，而这些函数可能只有在某些情况下才会执行得很慢。

那么，最好的解决办法是什么呢？

Answer 1

[编辑：我看到你添加了 python-2.7 标签，所以这对你可能没帮助，但对其他人可能有用或有趣。]

在Python 3中，你可以通过按 Control-C 来进入调试器。然后在调试器里，你可以查看程序的调用栈，看看程序在哪个地方花了时间。

Python 3.3.0 (default, Nov 23 2012, 10:26:01) 
>>> import time, pdb
>>> def foo(): time.sleep(1); foo()
... 
>>> pdb.run('foo()')
> <string>(1)<module>()
(Pdb) c
^C
Program interrupted. (Use 'cont' to resume).
--Call--
> <stdin>(1)foo()
(Pdb) w
  <stdin>(1)<module>()
  /.../pdb.py(1556)run()
-> Pdb().run(statement, globals, locals)
  /.../bdb.py(405)run()
-> exec(cmd, globals, locals)
  <string>(1)<module>()
  <stdin>(1)foo()
  <stdin>(1)foo()
  <stdin>(1)foo()
  <stdin>(1)foo()
  <stdin>(1)foo()
> <stdin>(1)foo()

你可以把这个方法想象成一种基于样本的性能分析，只不过这里只有一个样本！对于很多问题来说，一个样本就足够了。

Answer 2

我建议你使用日志模块来在代码的不同地方添加调试信息。使用这个日志模块，你可以很方便地开启或关闭调试信息，还可以控制显示哪些信息。

另外一个选择是使用一个集成开发环境（IDE），在里面你可以轻松地添加断点，这样就能帮助你找出代码在哪个地方进入了长循环。

Answer 3

一种解决方法是使用 cProfile，这是Python自带的工具，可以帮助你找出代码中花费时间最多的函数。重要的是，即使你用 KeyboardInterrupt 停止了代码，这个分析工具也能正常工作。因此，你可以启动代码并进行分析，过一两分钟后停止它，然后查看它花时间的地方。

运行代码时加上这两个额外的 -m 和 -o 参数：

python -m cProfile -o profile.txt myscript.py

然后在程序运行结束后，运行以下代码（比如在另一个脚本中）：

import pstats
p = pstats.Stats('profile.txt')
p.strip_dirs().sort_stats("time").print_stats()

这将打印出一个函数列表，按你在每个函数中花费的总时间排序。

这里有一个使用分析工具来调试无限循环的示例。假设 myscript.py 里有以下代码。

def f():
    while True:
        g(100000)

def g(n):
    x = []
    for i in range(n):
        x.append(n)

f()

当然，这会导致无限循环——函数 g 会被运行很多很多次。所以我运行上面的分析命令，然后在大约30-40秒后停止（其实可以更短）。它的分析结果会打印为：

Wed Jan 30 10:58:50 2013    profile.txt

         115414854 function calls in 37.705 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1155   25.787    0.022   37.020    0.032 test3.py:5(g)
115412541   10.060    0.000   10.060    0.000 {method 'append' of 'list' objects}
     1155    1.173    0.001    1.173    0.001 {range}
        1    0.685    0.685   37.705   37.705 test3.py:1(f)
        1    0.000    0.000   37.705   37.705 test3.py:1(<module>)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

注意，我们的无限循环函数 g 在花费时间的函数列表中排在最前面。

注意：代码花费所有时间在一个函数里，并不意味着循环就直接围绕着这个函数——它可能是由一个函数调用的，而这个函数又被另一个函数调用（等等），而那个函数可能在无限循环中（注意 append 也在列表的前面，因为它是在 g 内被调用的）。一种替代的方法是根据每个函数的累计时间进行排序，使用 .sort_stats("cum")。结合这两种方法，再加上一点侦探工作（查看代码并添加调试信息），应该能找到问题所在。