记一次蛋疼的性能调优

Python多进程库multiprocessing的封装

记一个诡异的问题

Dec 31

felix021 @ 2014-12-31 16:49 [IT » Python] 评论(2) , 引用(0) , 阅读(15071) | Via 本站原创

大 | 中 | 小

手头项目中有一个模块，一般情况下需要用python将数十万条数据加载到一个dict中处理，其中每条数据是一个小的dict，整体速度稍微有点慢（毕竟python不适合处理大量琐碎的小对象），由于在性能要求范围内，所以也没怎么在意。

但是在最近的性能测试中用160w+数据来压的时候，发现性能恶化得厉害。虽然算法是线性的，但是实际运行时间却明显不对劲。增加一些log后，发现在处理过程中，每隔几万条数据就会出现一个很明显的lag，而且lag的时间越拉越长。

由于不像是算法本身的问题，初步猜测可能是python中dict的rehash带来的时间开销。但是根据一般哈希表的实现方法，lag出现得太平均，又不是很符合逻辑。

大胆假设，小心求证，翻了一下python源码，Objects/dictobject.c 中 "static int dictresize(PyDictObject *mp, Py_ssize_t minused)" 函数被多处调用，其中PyDict_SetItem的末尾的调用是："dictresize(mp, (mp->ma_used > 50000 ? 2 : 4) * mp->ma_used)"，也就是说，在需要rehash的情况下，按4倍（少于50000个item）或2倍的规模扩大。

用下面这段代码测试1600w数据，将输出数据拷贝到Excel并生成图表，可以很明显地看出lag的出现规律与上述扩张规则非常相符。

begin = time.time()
i = 0
d = {}
while True:
i += 1
if i % 50000 == 0:
print '%d\t%.4f' % (i, time.time() - begin)
d[i] = i

{图一}

将上述代码稍作修改，每次插入的value是个dict，测试100w数据，生成图表，每隔10w左右产生一个lag，且lag时间越拉越长，与遇到的问题现象一致。

from copy import deepcopy
data = {'abcdefg': 1234, 'hijklnm': 4.0, 'opqrst': 'uvwxyz'}
begin = time.time()
i = 0
d = {}
while True:
i += 1
if i % 50000 == 0:
print '%d\t%.4f' % (i, time.time() - begin)
d[i] = deepcopy(data)

{图二}

因此大体可以判断问题出在大量零碎小对象上，很自然地，就联想到会不会是gc在捣蛋。查了一下，虽然Python对象内部是引用计数的管理方式，但是为了避免循环引用导致的内存泄漏，解释器还是内置了一个gc，当现有对象数量超过某个阈值以后扫描一下，看看是否可以回收一些空间。由于我们的代码中并不存在循环引用的对象，这种gc其实是没有意义的，于是把gc关掉再测：

from copy import deepcopy
import gc
gc.disable()
data = {'abcdefg': 1234, 'hijklnm': 4.0, 'opqrst': 'uvwxyz'}
begin = time.time()
i = 0
d = {}
while True:
i += 1
if i % 50000 == 0:
print '%d\t%.4f' % (i, time.time() - begin)
d[i] = deepcopy(data)

{图三}