asyncio 爬虫最隐蔽的性能问题是:在协程里放了一个同步的耗时调用。事件循环被卡住,所有其它协程(包括网络收发)一起停。这篇用一个心跳任务量化这种“卡住”,并对比线程池、进程池、to_thread 几种办法。
lxml.html.fromstring + xpath 统计链接数:40000 个链接,每次 89 ms(5 次中位数)
4.7 MiB 的页面一次解析约 89 ms;如果每个页面抓完立刻在协程里同步解析,20 个页面就是 20 次连续的 89 ms,事件循环被卡住,期间别的页面的数据也收不进来。
直接在协程里解析(同步调用):20 个页面全部完成 1776 ms;心跳 7 次,最大延迟 1293 ms,延迟超过 50 ms 的 3 次;解析结果一致 True run_in_executor(None, …)(线程池):20 个页面全部完成 1518 ms;心跳 118 次,最大延迟 15 ms,延迟超过 50 ms 的 0 次;解析结果一致 True run_in_executor(ProcessPoolExecutor(4), …)(进程池):20 个页面全部完成 557 ms;心跳 67 次,最大延迟 13 ms,延迟超过 50 ms 的 0 次;解析结果一致 True
心跳任务显示:直接解析时最大延迟 1293 ms(多次运行 657–1293 ms),放进线程池后只剩 15 ms,进程池 13 ms。但线程池对 CPU 密集的 lxml 解析几乎没有加速(总耗时 1518 ms 对 1776 ms),进程池才让 4 个核心真正并行(557 ms)。线程池为什么没有加速,下一批文章会单独看(lxml 与 GIL);进程池要付序列化页面内容的代价,这里没有拆开测。
协程里直接 requests.get:10 个请求共 1079 ms;心跳 1 次,最大延迟 1069 ms,延迟超过 50 ms 的 1 次;服务器同时处理的峰值 1 aiohttp:10 个请求共 112 ms;心跳 10 次,最大延迟 2 ms,延迟超过 50 ms 的 0 次;服务器同时处理的峰值 10 asyncio.to_thread(requests.get, …):10 个请求共 114 ms;心跳 10 次,最大延迟 2 ms,延迟超过 50 ms 的 0 次;服务器同时处理的峰值 10
在 async def 里直接写 requests.get(...) 是最典型的错误:服务器看到的并发峰值只有 1,10 个请求花了 1079 ms,事件循环整段时间没有醒过一次。换成 aiohttp 或者 asyncio.to_thread(requests.get, …) 都能恢复 10 个并发(约 112–114 ms)。
Executing <Task finished name='Task-1' coro=<main() done, defined at …/dbg.py:3> … took 0.352 seconds (进程退出码 0,这是 asyncio 记在 stderr 上的警告,不是异常)
asyncio 调试模式会在回调超过 slow_callback_duration(默认 0.1 秒)时在 stderr 上打一条 Executing … took … seconds 的警告。它不抛异常、不改变退出码,所以要把日志看起来。