3. 调试和性能优化¶
3.1. 定制调试信息¶
3.1.1. 打印文件名和行号¶
借助sys.exc_info 模块自己捕获异常,来打印调用者信息,同时打印当前调试信息。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 | import sys
def xprint(msg=""):
try:
print("do try")
raise Exception
except:
f = sys.exc_info()[2].tb_frame.f_back
print('%s[%s]: %s' % (f.f_code.co_filename, str(f.f_lineno), msg))
def test_xprint():
xprint()
xprint("%d %s" %(10, "hello"))
test_xprint()
>>>
C:/Users/Red/.spyder/test/test.py[218]:
C:/Users/Red/.spyder/test.py[219]: 10 hello
|
3.1.2. 异常时打印函数调用栈¶
异常发生时,Python默认处理方式将中断程序的运行,有时候我们希望程序继续运行。 可以通过 try 语句结合 sys.exc_info() 和 traceback模块抛出异常,并给出提示信息。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | import traceback
import sys
def xtry(runstr):
ret, status = None, True
try:
ret = eval(runstr)
except:
info = traceback.format_exc()
try:
raise Exception
except:
f = sys.exc_info()[2].tb_frame.f_back
print('%s[%s]: %s' % (f.f_code.co_filename, str(f.f_lineno), info))
status = False
return status, ret
|
xtry()函数接受一个字符串作为表达式,与xprint()函数类似,在异常出现时打印出文件名和行号,并且借助traceback模块格式化调用栈信息。 同时返回是否出现异常和表达式的执行结果,status为True表示可以正常执行,否则出现异常。
下面是一个示例:
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 | def divide(a, b):
return a / b
status, ret = xtry("divide0(100, 0)")
print(status, ret)
print("still running!!") # 继续执行
>>>
C:/Users/Red/.spyder/dolist/except.py[37]: Traceback (most recent call last):
File "C:/Users/Red/.spyder/dolist/except.py", line 22, in xtry
ret = eval(runstr)
File "<string>", line 1, in <module>
File "C:/Users/Red/.spyder/dolist/except.py", line 12, in divide0
try:
ZeroDivisionError: division by zero
False None
still running!!
|
3.2. 断言和测试框架¶
3.2.1. assert 语句¶
断言语句 assert 在表达式为假时抛出断言异常 AssertionError 并终止程序的执行。 这在调试和测试代码时非常有用。
0 1 2 3 | assert 1 == 2
assert isinstance('str', str)
assert 0
assert False
|
0 和 False是等价的,1 和 True 是等价的,当表达式为假时,抛出如下的异常信息:
0 1 2 3 4 5 6 | assert 1 == 2
>>>
File "C:/Users/Red/.spyder/except.py", line 107, in <module>
assert 1 == 2
AssertionError
|
断言语句还支持一个格式化字符串参数,以逗号区分,用于提供更明确的断言信息。
0 1 2 3 4 5 6 7 | oct_num = -1
assert oct_num in range(10), "Oct number must be in (%d-%d)" % (0, 9)
>>>
File "C:/Users/Red/.spyder/except.py", line 107
assert oct_num in range(10), "Oct number must be in (%d-%d)" % (0, 9)
AssertionError: Oct number must be in (0-9)
|
专门的测试框架工具通常会对 Python 自带的断言功能进行扩展,以提供更强大的测试和诊断能力。
3.2.2. 单元测试模块 unittest¶
单元测试主要针对最基础的代码可测单元进行测试,比如一个表达式,一个变量值的合法性,一个函数的入参和出参规格直至一个模块的功能。 著名的极限编程中的测试驱动开发(TDD:Test-Driven Development)就是以单元测试为基础的开发方式, 单元测试代码在编写功能代码时同时进行,每次对代码的增删和缺陷修复都要进行单元测试,以保证代码是符合预期的。 这很像在修路的同时,同时修筑了足够高的防护栏,而在赛车选手变换各类驾驶技巧时,不会冲出赛道。
可以这样说,只要单元测试没有漏洞,编码者就有底气说问题已经彻底修复了。
3.2.2.1. unittest 测试用例¶
Python 自带单元测试框架 unittest , 它将测试用例定义为 TestCase 类。 编写单元测试时,首先需要编写一个测试类,并继承 unittest.TestCase,类中的方法必须以 test 开头:
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 | import unittest
class test_suit1(unittest.TestCase):
def test1(self):
'''test suit 1''' # 测试用例描述,同用例标题一并显示在测试报告里
self.assertEqual(1, 1)# 测试用例断言,期望 1 == 1,否则抛出异常
class test_suit2(unittest.TestCase):
def test2(self):
'''test suit 2'''
self.assertEqual(2, 0)
unittest.main() # 可以传入 verbosity=1 打印每一测试用例结果
>>>
.F
======================================================================
FAIL: test2 (unit.test_suit2)
test suit 2
----------------------------------------------------------------------
Traceback (most recent call last):
File "/home/red/sdc/lbooks/ml/unit.py", line 14, in test2
self.assertEqual(2, 0)
AssertionError: 2 != 0
----------------------------------------------------------------------
Ran 2 tests in 0.001s
|
测试结果的第一行给出所有测试用例的结果, . 和 F 分别表示测试通过或失败,每一个测试用例对应一个字符。
接着给出出错所用例的类名和描述,并附上对应出错代码的文件和行号等信息。最后给出总的运行用例数和测试耗时。
上面的示例直接通过 unittest.main() 函数运行,也可以在命令行中调用 unittest 模块,注意要注释掉 unittest.main()。
0 | python3.4 -m unittest unit_sample.py # 可以添加 -v 打印每一测试用例结果
|
unittest 目前支持如下断言函数:
名称 等价 版本 assertEqual(a, b) a == b assertNotEqual(a, b) a != b assertTrue(x) bool(x) is True assertFalse(x) bool(x) is False assertIs(a, b) a is b 3.1 assertIsNot(a, b) a is not b 3.1 assertIsNone(x) x is None 3.1 assertIsNotNone(x) x is not None 3.1 assertIn(a, b) a in b 3.1 assertNotIn(a, b) a not in b 3.1 assertIsInstance(a, b) isinstance(a, b) 3.2 assertNotIsInstance(a, b) not isinstance(a, b) 3.2
3.2.2.2. unittest 测试套件¶
上面的例子在实际的运行中,测试顺序并不是严格按照我们定义的测试用例顺序执行,有时我们的测试用例可能依赖执行顺序,比如打开文件,写文件等。 测试套件 TestSuite 可以解决该问题,同时它可以组织多个脚本文件的测试用例。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 | class TestMathFunc(unittest.TestCase):
def test_abs(self):
"""Test method abs()"""
self.assertEqual(1, abs(-1))
self.assertEqual(1, abs(1))
def test_max(self):
"""Test method max(x1,x2...)"""
self.assertEqual(2, max(1, 2))
def test_min(self):
"""Test method min(x1,x2...)"""
self.assertEqual(1, min(1, 2))
# 创建测试套件
suite = unittest.TestSuite()
# 1. 添加部分测试用例
tests = [TestMathFunc("test_max"), TestMathFunc("test_min")]
suite.addTests(tests)
# 2. 添加所有测试用例
suite.addTest(unittest.makeSuite(TestMathFunc))
runner = unittest.TextTestRunner(verbosity=1) # verbosity=0-2 调整输出
runner.run(suite)
>>>
.....
----------------------------------------------------------------------
Ran 5 tests in 0.000s
OK
|
示例中提供了两种向测试套件添加测试用例的方法,通过 addTests() 部分添加测试用例或通过 addTest() 导入套件中全部用例。测试结果中显示运行了5个用例。
3.2.2.3. 测试结果输出到文件¶
0 1 2 3 4 5 | ......
suite.addTest(unittest.makeSuite(TestMathFunc))
with open('unittest_report.txt', 'w') as f:
runner = unittest.TextTestRunner(stream=f, verbosity=1)
runner.run(suite)
|
查看 unittest_report.txt 文件,可以发现与上面示例相同的输出。这里采用 unittest 自带的 TextTestRunner(),输出结果为普通文本文件。 verbosity 参数可以控制执行结果的输出:0 是简单报告,1 是一般报告,2 是详细报告。
可以借助 HTMLTestRunner 和 xmlrunner 模块生成 html 或者 xml 格式的报告文件。
3.2.2.4. 测试环境的布置和清理¶
如果测试需要在每次执行之前准备环境,并且在每次执行完后需要进行测试环境的撤销,比如执行前创建临时文件夹,临时文件,测试用数据,连接数据库,创建并连接套接字等, 执行完成之后要删除临时文件夹,临时数据,断开连接。不可能为了每个测试用例都添加准备环境、清理环境的操作。
我们只要在测试类中,重写 unnitest 模块提供的 setUp() 和 tearDown() 两个方法即可。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 | class TestMathFunc(unittest.TestCase):
def setUp(self):
print("Prepare unittest environment.")
def tearDown(self):
print("Clean up unittest environment.")
......
>>>
Prepare unittest environment.
Clean up unittest environment.
.Prepare unittest environment.
Clean up unittest environment.
......
|
可以看到 setUp() 和 tearDown() 在每个测试用例执行前后都会执行一次。 也可以借助这一机制,来统计每个测试用例的运行时间。
如果想要在所有测试用例执行之前和结束之后,只执行一次准备和清理动作,可以用 setUpClass() 与 tearDownClass()。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 | class TestMathFunc(unittest.TestCase):
@classmethod
def setUpClass(cls):
print("Prepare unittest environment.")
@classmethod
def tearDownClass(cls):
print("Clean up unittest environment.")
......
>>>
Prepare unittest environment.
.....Clean up unittest environment.
----------------------------------------------------------------------
Ran 5 tests in 0.000s
OK
|
注意:必须使用 classmethod 修饰符来指明 setUpClass() 与 tearDownClass() 是类的方法,不需要实例化即可执行。
3.2.2.5. 跳过特定测试用例¶
如果想要跳过某个测试用例不执行,可以在测试函数前使用 skip 修饰器。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 | class TestMathFunc(unittest.TestCase):
def test_abs(self):
"""Test method abs()"""
self.assertEqual(1, abs(-1))
self.assertEqual(1, abs(1))
@unittest.skip("Don't run it now!")
def test_max(self):
"""Test method max(x1,x2...)"""
self.assertEqual(2, max(1, 2))
......
>>>
s..s.
----------------------------------------------------------------------
Ran 5 tests in 0.001s
OK (skipped=2)
|
可以看到在 test_max() 用例在执行时标记为 s,表示跳过。
skip 修饰器一共有三种:
- unittest.skip(reason) 无条件跳过。
- unittest.skipIf(condition, reason) 当 condition 为 True 时跳过。
- unittest.skipUnless(condition, reason) 当 condition 为 False 时跳过。
3.2.2.6. 参数化测试¶
如果要针对某个函数,或者类进行多种数据输入组合的测试,特别是完整性测试时,为每一种情况写一句断言,是非常麻烦的事情,借助参数化模块 parameterized,可以解决这一问题。
安装它的命令为 sudo pythonX.Y -m pip install parameterized,注意 Python 版本。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 | from parameterized import parameterized
class TestCanDrive(unittest.TestCase):
@parameterized.expand([
[True, True, False], # 也可以是 tuple
[True, False, True],
[False, False, False],
[False, False, False]
])
# 运行时遍历上述列表里的参数,把所有项执行一遍
def test_can_drive(self, with_license, drunk, expected):
status = can_drive(with_license, drunk)
self.assertEqual(status, expected)
suite.addTest(unittest.makeSuite(TestCanDrive))
runner = unittest.TextTestRunner(verbosity=1)
runner.run(suite)
>>>
....
----------------------------------------------------------------------
Ran 4 tests in 0.000s
OK
|
尽管我们只定义了一个测试函数,却运行了4个测试用例。如果测试用例数据非常多,我们可以把需要传递给 parameterized.expand() 函数的列表参数的数据放在一个文件里面,使用的时候读取。这样在修改维护测试数据上都将轻松很多。
3.2.2.7. 批量执行测试用例¶
尽管通过 import 所有的测试模块脚本,并将它们加入到当前总的测试脚本中的测试套件中,以实现批量处理,但是每次 增删模块,都需要修改当前测试脚本,非常麻烦。
unittest 里的 defaultTestLoader.discover() 方法可以对指定路径下的测试脚本文件进行通配符匹配,直接返回测试套件。
0 1 2 3 4 | cases_suit = unittest.defaultTestLoader.discover("test_dir", \
pattern="test_*.py", top_level_dir=None)
runner = unittest.TextTestRunner(verbosity=1)
runner.run(cases_suit)
|
注意:defaultTestLoader.discover() 方法只处理包类型目录,也即目录下必须存在 __init__.py 文件,top_level_dir 指明包的顶层目录。
3.3. 性能分析¶
在分析python代码执行效率时经常使用time包中的time.time()和time.clock()函数。但是两者是有区别的。
根据cpu的运行机制,cpu是多任务的,如在多进程的执行过程中,一段时间内会被多个进程或者线程占用。 一个进程从开始到结束其实是在这期间的一系列时间片(tick)上断断续续执行的。 此外,如果cpu是多核的或者超线程的,那么多线程的程序执行占用的cpu时间也可能多于真实世界流逝的时间。所以这就引出了程序执行的cpu时间(在这段系统时间内程序占用cpu运行的时间)和墙上时钟(wall time)。
绝对时间(absolute time):也即真实世界时间(real-world time),由time.time()返回。 它是从某个过去固定的时间点(比如 UNIX epoch为00:00:00 UTC on 01/01/1970)到当前时刻 真实世界经过的秒数。系统通过RTC(real-time clock)电路和纽扣电池来保持该时间。系统启动时读取 该秒数,在运行时,也可以通过NTP协议动态修改该秒数。系统基于该值,通过时区和夏令时转换显示为 便于理解的当地时间。UTC时区又被称为GMT或者Zulu时间。
real-world time或者real time在英文中还被称为墙上时钟(wall time或者wall-clock time),所以time.time() 两次返回的值的差就和墙上挂钟或者手表走过的时间是一样的。计算机中的RTC时钟系统是可以进行调整的, 这和真实世界中的钟表是一样的,任何人造计时装置都会走快走慢,RTC时钟系统也一样。
3.3.1. time和clock函数¶
- time.time()统计的是墙上时钟(wall time),也就是系统时钟的时间戳(1970纪元后经过的浮点秒数)。所以两次调用的时间差即为系统经过的总时间。
- time.clock()统计的是cpu时间,这在统计某一进程或者线程或函数的执行速度最为合适。两次调用time.clock()函数值即为程序运行占用的cpu时间。cpu时间又可细分为用户时间(User Time)和系统时间(System Time),分别表示进程/线程运行在用户态和内核态所占用的时间。
这两个函数均返回浮点数,单位秒。以下是两个函数的对比:
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 | import time
def addto(n):
time.sleep(3) # 区分clock()和time()不同平台实现不同
return sum(range(n + 1))
start = time.time()
addto(10000000)
end = time.time()
print("time.time():\t\t%f" % (end - start))
start = time.clock()
addto(10000000)
end = time.clock()
print("time.clock():\t\t%f" % (end - start))
>>> # Windows 运行结果
time.time(): 3.573660
time.clock(): 3.552534
>>> # Linux 运行结果
time.time(): 4.246678
time.clock(): 1.216453
|
以上结果令人迷惑,在不同的平台上运行结果不一致。Linux上time.clock()要比time.time()短得多,而Windows平台相差不多。
如果去掉测试函数中的sleep(3),则两个函数在Linux平台上的输出也变成接近的。睡眠函数让程序让出cpu,显然在Linux平台上clock()函数统计的是程序实际消耗的cpu时间,而Windows平台返回的则是墙上时间。
通过查看系统clock()函数的底层调用,可以了解不同平台的区别。
0 1 2 3 4 5 6 7 | print(time.get_clock_info("clock"))
>>> # Windows 运行结果
namespace(adjustable=False, implementation='QueryPerformanceCounter()',
monotonic=True, resolution=3.9506172839506174e-07)
>>> # Linux 运行结果
namespace(adjustable=False, implementation='clock()', monotonic=True, resolution=1e-06)
|
Windows 平台底层调用 QueryPerformanceCounter() 函数,它实际上返回的就是墙上时间。
由以上测试用例,可以看出采用 time.clock() 来统计代码运行效率,具有平台不确定性,代码不可移植,该函数官方在Python 3.3版本已不再推荐使用。已被time.perf_counter()和time.process_time()取代。
详细说明请参考 PEP0418 。
3.3.2. 高精度时间统计函数¶
高精度的时间间隔统计的实现基于cpu频率计数器,最高可以精确到cpu的工作频率。
time.perf_counter() 函数返回cpu时间,包括用户时间和系统时间,sleep 的时间,它包含了当前函数开始和结束间隔内被调度出的时间。
time.process_time() 函数返回本进程或者线程的cpu占用时间,包括用户时间和系统时间,不包含 sleep 时间。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | start = time.perf_counter()
addto(10000000)
end = time.perf_counter()
print("time.perf_counter():\t%f" % (end - start))
start = time.process_time()
addto(10000000)
end = time.process_time()
print("time.process_time():\t%f" % (end - start))
>>> # Windows 运行结果
time.perf_counter(): 3.553474
time.process_time(): 0.578125
>>> # Linux 运行结果
time.perf_counter(): 4.178790
time.process_time(): 1.130667
|
通常情况下,使用这两个函数来对代码效率进行简单统计。
3.3.3. timeit性能分析模块¶
timeit模块默认使用 perf_counter() 时钟计时函数。
0 1 2 3 4 5 6 7 | import timeit
# 通过 timer 参数可以指定计时器
# print(timeit.timeit('x=1', timer=time.process_time))
print(timeit.default_timer)
>>>
<built-in function perf_counter>
|
timeit模块提供了 timeit() 和 repeat() 函数用于对代码片段或者函数进行重复测试。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 | #看执行1000000次x=1的时间:
print(timeit.timeit('x=1'))
#看x=1的执行时间,执行1次(number可以省略,默认值为1000000):
print(timeit.timeit('x=1', number=1))
#看一个列表生成器的执行时间,执行10000次:
t = timeit.timeit('[i for i in range(100) if i%2==0]', number=10000)
print(t)
t = timeit.timeit('addto(100000)', 'from __main__ import addto', number=1000)
print(t)
>>>
0.013765925919869915
3.950553946197033e-07
0.07114627161354292
2.6092641975410515
|
repeat和timeit用法相似,多了一个repeat参数,表示重复测试的次数(默认值为3), 返回值为一个时间的列表。
0 1 2 3 4 5 6 | t = timeit.repeat('addto(100000)', 'from __main__ import addto', number=100, repeat=3)
print(t)
print(min(t))
>>>
[0.2632288394961506, 0.25551288889255375, 0.2601240493822843]
0.25551288889255375
|
3.3.4. cProfile 和 profile¶
确定性性能分析((Deterministic Profiling))指的是反映所有的函数调用,返回,和异常事件的执行所用的时间,以及它们之间的时间间隔。相比之下,统计性性能分析指的是取样有效的程序指令,然后推导出所需要的时间,后者花费比较少的开销,但是给出的结果不够精确。
因Python是解释性语言,在执行程序的时候,需要解释器解析执行,这部分的执行是不需要进行性能分析的。Python自动为每一个事件提供一个hook,来定位需要分析的代码。除此之外,因为Python解释型语言的本质往往需要在执行程序的时候加入很多其它的开销,而确定性性能分析只会加入一点点处理开销。这样一来,确定性性能分析其实开销不大,还可以提供丰富的统计信息。
函数调用次数的统计能够被用于确定程序中的bug,比如一个不符合常理的次数,明显偏多之类的,还可以用来确定可能的内联函数。函数内部运行时间的统计可被用来确定”hot loops”,那些运行时间过长,需要优化的部分;累计时间的统计可被用来确定比较高层次的错误,比如算法选择上的错误。
cProfile 和 profile 均是标准库内建的确定性性能分析工具。
profile是原始的纯Python分析器。它提供的函数接口和调用方式与cProfile完全兼容。与cProfile相比,用户可以根据需要,在脚本层面扩展该模块。
cProfile是默认的分析工具,它基于lsprof,一个用C语言实现的扩展库, 底层调用 C 语言接口提供的动态库,在Unix系统上,它通常是位于Python共享库文件夹 /usr/lib/pythonx.y/lib-dynload/下的_lsprof.cpython-xxx-linux-gnu.so。所以相对于profile,它的运行效率要高。
使用 cProfile 进行性能分析有两种方式,可以使用命令行执行,也可以在脚本中导入函数。 使用命令行执行时,无需对脚本做任何改动。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 | # cprofile.py 中的测试代码
def addto0(n):
total = 1.0
for i in range(1,n+1):
total += i
return total
def addto1(n):
return addto0(n)
def test_add(n):
for i in range(2):
addto0(n)
for i in range(3):
addto1(n)
test_add(10000000)
# 直接命令行调用cProfile模块
# python -m cProfile -s cumulative cprofile.py
12 function calls in 5.643 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 5.643 5.643 {built-in method exec}
1 0.000 0.000 5.643 5.643 cprofile.py:7(<module>)
1 0.000 0.000 5.643 5.643 cprofile.py:19(test_add)
5 5.643 1.129 5.643 1.129 cprofile.py:9(addto0)
3 0.000 0.000 3.385 1.128 cprofile.py:16(addto1)
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
|
-s 参数指明输出排序方式为 cumulative,也即按照函数累计耗时大小排序。这方便找到耗时最久的代码点。
第一行指明脚本中共执行了 12 次函数调用,一共耗时 5.642秒。
- ncalls:每个函数调用的次数,这里它们的和正好是12。
- tottime: 每个函数调用累计耗时,不含函数中子函数耗时。
- percall: 函数每次调用累计耗时的平均时间,等于 tottime / ncalls。
- cumtime: 每个函数调用累计耗时,含函数中子函数耗时。
- precall:函数每次调用累计耗时的平均时间,等于 cumtime / ncalls。
- filename:lineno(function):给出文件名,行号和函数名
test_add()函数被调用1次,其中调用了2次addto0() 和 3次addto1(),addto1()中调用了addto0(), 所以 addto0() 一共被调用了5次。
-s 参数还支持 ncalls,tottime,filename,line和module等排序方式。
代码中直接调用cProfile函数,这里用 ncalls排序:
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | import cProfile
# 直接把分析结果打印到控制台
cProfile.run("test_add(10000000)", sort="ncalls")
>>>
12 function calls in 5.693 seconds
Ordered by: call count
ncalls tottime percall cumtime percall filename:lineno(function)
5 5.693 1.139 5.693 1.139 cprofile.py:11(addto0)
3 0.000 0.000 3.319 1.106 cprofile.py:18(addto1)
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
1 0.000 0.000 5.693 5.693 {built-in method exec}
1 0.000 0.000 5.693 5.693 <string>:1(<module>)
1 0.000 0.000 5.693 5.693 cprofile.py:21(test_add)
|
3.3.4.1. pstats分析输出结果¶
cProfile 统计结果输出到文件:
0 1 2 | # python -m cProfile -o profile.stats cprofile.py # 命令方式
cProfile.run("addto(10000000)", filename="profile.stats")# 脚本调用函数方式
|
pstates 模块完成对文件 profile.stats 的分析。print_stats()输出跟之前一样的累计报告信息。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 | import pstats
p = pstats.Stats("profile.stats")
p.sort_stats("cumulative")
p.print_stats()
>>>
12 function calls in 5.631 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 5.631 5.631 {built-in method exec}
1 0.000 0.000 5.631 5.631 cprofile.py:7(<module>)
1 0.000 0.000 5.631 5.631 cprofile.py:21(test_add)
5 5.631 1.126 5.631 1.126 cprofile.py:11(addto0)
3 0.000 0.000 3.378 1.126 cprofile.py:18(addto1)
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
|
为了追溯关心的函数,可以通过print_callers()打印调用者的信息。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 | p.print_callers()
>>>
Ordered by: cumulative time
Function was called by...
ncalls tottime cumtime
{built-in method exec} <-
cprofile.py:7(<module>) <- 1 0.000 5.631 {built-in method exec}
cprofile.py:21(test_add) <- 1 0.000 5.631 cprofile.py:7(<module>)
cprofile.py:11(addto0) <- 3 3.378 3.378 cprofile.py:18(addto1)
2 2.252 2.252 cprofile.py:21(test_add)
cprofile.py:18(addto1) <- 3 0.000 3.378 cprofile.py:21(test_add)
{method 'disable' of '_lsprof.Profiler' objects} <-
|
反过来,还可以通过print_callees()打印被调用者的信息。
0 1 2 3 4 5 6 7 8 9 10 11 12 13 | p.print_callees()
>>>
Ordered by: cumulative time
Function called...
ncalls tottime cumtime
{built-in method exec} -> 1 0.000 5.631 cprofile.py:7(<module>)
cprofile.py:7(<module>) -> 1 0.000 5.631 cprofile.py:21(test_add)
cprofile.py:21(test_add) -> 2 2.252 2.252 cprofile.py:11(addto0)
3 0.000 3.378 cprofile.py:18(addto1)
cprofile.py:11(addto0) ->
cprofile.py:18(addto1) -> 3 3.378 3.378 cprofile.py:11(addto0)
{method 'disable' of '_lsprof.Profiler' objects} ->
|
查看前特定行的函数信息,如下所示:
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 | # 打印指定的前多少行
p.print_stats(2)
# 以百分比,打印前50%的行数
p.print_stats(0.5)
>>>
...
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 5.631 5.631 {built-in method exec}
1 0.000 0.000 5.631 5.631 cprofile.py:7(<module>)
...
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 5.631 5.631 {built-in method exec}
1 0.000 0.000 5.631 5.631 cprofile.py:7(<module>)
1 0.000 0.000 5.631 5.631 cprofile.py:21(test_add)
|
查看给定的函数调用信息,比如想查看哪些函数调用了 addto0() 函数:
0 1 2 3 4 5 6 7 8 9 | p.print_callers("addto0")
>>>
Ordered by: cumulative time
List reduced from 6 to 1 due to restriction <'addto0'>
Function was called by...
ncalls tottime cumtime
cprofile.py:11(addto0) <- 3 3.378 3.378 cprofile.py:18(addto1)
2 2.252 2.252 cprofile.py:21(test_add)
|
同理,如果要查看test_add()函数调用了哪些函数:
0 1 2 3 4 5 6 7 8 9 | p.print_callees("test_add")
>>>
Ordered by: cumulative time
List reduced from 6 to 1 due to restriction <'test_add'>
Function called...
ncalls tottime cumtime
cprofile.py:21(test_add) -> 2 2.252 2.252 cprofile.py:11(addto0)
3 0.000 3.378 cprofile.py:18(addto1)
|
3.3.4.2. cProfile数据可视化¶
使用 gprof2dot 脚本和 dot命令可以根据cProfile统计信息生成函数调用流程图。
0 1 | # pip install gprof2dot
# gprof2dot -f pstats profile.stats | dot -Tpng -o output.png
|
3.3.5. 逐行分析模块line_profiler¶
3.4. ipython¶
ipython 是基于 Python 的交互式 shell,比默认的 python shell 强大很多:支持变量自动补全,自动缩进,支持 bash shell 命令,内置了许多很有用的功能和函数。
ipython 安装非常简单,Windows 平台需额外安装 pyreadline 用于支持命令补全和颜色显示等功能:
0 1 | # pip install ipython
# pip install pyreadline
|
ipython 的交互提示符总是以 In [n]: 开始,其中 n 表示输入命令的编号:
0 1 2 3 4 5 6 | (py36) C:\Users\Red>ipython
Python 3.6.2 |Continuum Analytics, Inc.| (default, Jul 20 2017, 12:30:02)
[MSC v.1900 64 bit (AMD64)]
Type 'copyright', 'credits' or 'license' for more information
IPython 6.1.0 -- An enhanced Interactive Python. Type '?' for help.
In [1]:
|
3.4.1. ipython 功能简介¶
查看模块中所有函数,可以在 ‘.’ 之后按 Tab 键:
0 1 2 3 4 | In [11]: np.random.[Tab]
absolute_import bytes() division geometric() info
bench() chisquare() exponential() get_state() laplace()
beta() choice() f() gumbel() Lock()
binomial() dirichlet() gamma() hypergeometric() logistic()
|
tab 键可以自动补全命令或者函数,极大提高开发效率:
0 1 2 | In [4]: %hist[Tab]
%hist
%history
|
在变量的前面或后面添加问号(?)显示该对象的帮助信息,这就叫做对象的内省。这比 python 中的 help 命令方便多了:
0 1 2 3 4 5 6 7 | # 查看 ? 自身的帮助信息
In [16]: ?
......
? -> Introduction and overview of IPython's features (this screen).
object? -> Details about 'object'.
object?? -> More detailed, verbose information about 'object'.
%quickref -> Quick reference of all IPython specific syntax and magics.
help -> Access Python's own help system.
|
?? 可显示更多信息,例如函数源码。
0 1 2 3 4 5 6 7 8 9 10 | In [21]: def test(a):
...: print(a)
...:
In [22]: test??
Signature: test(a)
Source:
def test(a):
print(a)
File: c:\users\red\<ipython-input-21-e5cfd00ad69a>
Type: function
|
魔术命令是 ipython 的另一大特色:
0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 | %quickref 显示IPython的快速参考
%magic 显示所有魔术命令的详细文档
%debug 从最新的异常跟踪的底部进入交互式调试器
%hist 打印命令的输入(可选输出)历史
%pdb 在异常发生后自动进入调试器
%paste 执行剪贴板中的Python代码
%cpaste 打开一个特殊提示符以便手工粘贴待执行的Python代码
%reset 删除interactive命名空间中的全部变量/名称
%page OBJECT 通过分页器打印输出OBJECT
%run script.py 在IPython中执行一个Python脚本文件
%prun statement 通过cProfile执行statement,并打印分析器的输出结果
%time statement 报告statement的执行时间
%timeit statement 多次执行statement以计算系综平均执行时间。对那些执行时 间非常小的代码很有用
%who、%who_ls、%whos 显示interactive命名空间中定义的变量,信息级别/冗余度可变
%xdel variable 删除variable,并尝试清除其在IPython中的对象上的一切引用
|
%time 和 %timeit 是非常便利的测试代码执行时间的魔术命令,time 执行一次,而 timeit 执行多次取平均。
0 1 2 3 4 5 6 7 8 9 10 11 | In [31]: def sumto(n):
...: sum = 0
...: for i in range(n+1):
...: sum += i
...: return sum
In [32]: %time sumto(100000)
Wall time: 6.98 ms
Out[32]: 5000050000
In [33]: %timeit sumto(100000)
7.44 ms ± 361 µs per loop (mean ± std. dev. of 7 runs, 100 loops each)
|
更多命令请使用 %quickref 和 %magic 来显示 IPython 快速参考。
3.5. Jupyter Notebook¶
Jupyter Notebook 的前身被称为 IPython notebook,是一个交互式的 web 应用程序,显然 Notebook 是笔记本的意思,可以将命令和结果记录为一个扩展名为 .ipynb 的文件,通过它非常方便创建和共享程序文档,支持数学方程,内嵌图片和 markdown 语法。
Jupyter Notebook 建立在 IPython 基础之上,所以继承了 IPython 的强大扩展功能,是网页版的 IPython,所以访问它就要通过浏览器。
0 1 | $ pip install jupyter
$ jupyter notebook # 启动命令
|
启动 jupyter notebook 之后在浏览器中输入 http://localhost:8888 即可。
如果我们在 github 或者其他网站发现一个 .ipynb,或者 email 中发来嵌入一条链接,我们想在线浏览该文件,可以通过 https://nbviewer.jupyter.org/ 网站实现:只要在页面的地址框填入 .ipynb 超链接即可。