问题
Python 脚本使用 requests 模块做 HTTP 请求,验证代理 IP 的可用性,速度等。 设定 HTTP 请求的 connect timeout 与 read response timeout 均为 3 秒,allow_redirects 设定为 False。Linux shell 启动 10 个 Python 进程持续从 Redis 队列中读取数据。监控软件持续获取进程内存信息。多个小时之后出现,极个别进程内存占用量暴增,其余进程内存均处于正常且相等的水平。
脚本分析
猜测 Python 脚本出现内存过大问题的可能原因:
- 重复,相互引用
- 重复实例化
- 打开文件数量过多,并且未释放
针对上面猜测的检查方案:
- print 打印主函数中的每个对象,在 while 循环中,被引用的次数。结果:无重复引用。
- memory_profiler 与 objgraph 模块输出主函数内存使用情况,连续测试 10K 条IP,未发现内存爆增问题
- lsof 命令对比 异常进程与正常进程打开的文件对比,结果:打开文件相同,没有异常。
外部分析
外部分析工具:
- strace 跟进进程调用系统调用
- lsof 检查进程的开发的句柄,包括文件,网络连接等
- tcpdump 抓包,进程网络连接等数据包。
首先 strace 跟踪 Python脚本的系统调用。
正常进程的系统调用是这样的:
gettimeofday({1472383894, 582049}, NULL) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 4
fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(7777), sin_addr=inet_addr("123.57.190.51")}, 16) = -1 EINPROGRESS (Operation now in progress)
poll([{fd=4, events=POLLOUT}], 1, 3000) = 1 ([{fd=4, revents=POLLOUT|POLLERR|POLLHUP}])
getsockopt(4, SOL_SOCKET, SO_ERROR, [111], [4]) = 0
close(4) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=414, ...}) = 0
select(0, NULL, NULL, NULL, {1, 0}) = 0 (Timeout)
stat("/root/.netrc", 0x7ffd418e1fe0) = -1 ENOENT (No such file or directory)
stat("/root/_netrc", 0x7ffd418e1fe0) = -1 ENOENT (No such file or directory)
异常进程的系统调用是这样的:
gettimeofday({1472384309, 884266}, NULL) = 0
poll([{fd=4, events=POLLIN}], 1, 3000) = 1 ([{fd=4, revents=POLLIN}])
recvfrom(4, "\22\4p\327\252\313\5opera\20\4x\244)\303\5opera\21\4r}?\265\5o"..., 3907, 0, NULL, NULL) = 1448
gettimeofday({1472384310, 89236}, NULL) = 0
poll([{fd=4, events=POLLIN}], 1, 3000) = 1 ([{fd=4, revents=POLLIN}])
recvfrom(4, "\247p\364\0%\4ry\353\355\4jake\22\4p\327\227b\5opera\22\4\312C("..., 2459, 0, NULL, NULL) = 506
异常进程无休止的系统调用 poll 获取数据,开辟内存使用。初步猜测,TCP连接上有问题。
第二步 lsof 查看异常进程建立的网络连接。
python 12245 root 4u IPv4 9012524 0t0 TCP 10.0.21.226:54452->s30-06-09.opera-mini.net:9000 (ESTABLISHED)
根据 Python脚本的设定,HTTP请求, 连接超时(connect timeout)与读取回复超时 (read response timeout) 都是 3 秒。也就是说一般情况,进程不应该对这个IP(域名)连接了。
在6秒之后,在此查看该进程的 tcp连接,发现已然与此IP建立连接。
思考:为什么 Python requests 模块设定的超时时间无效?
第三步 tcpdump 抓去这个异常进程正在连接的 的数据包。
tcpdump -i eth0 host 107.167.113.32 tcp port 9000 -w /tmp/connect.log
tcpdump 抓到的数据包扔到 WireShake 打开分析。
TCP标志位:ACK 与 PSH。(传输数据)
持续观察之后,确定为特殊IP的特殊端口,在TCP建立连接之后,回传送大量垃圾无用数据。导致极个别进程出现内存异常问题。
另外由于 TCP 层持续传送数据, 经过测试,无论是 urllib2 还是 requests 的超时时间设定对此类问题均无效。
处理方案
思考:
- 由于是 TCP 层的连接问题,HTTP层的超时时间对此无效,需要外部对每次多 HTTP 连接作超时处理。
- 此脚本行为更多占用的系统 IO 而非 CPU 计算,多进程方案会占用很多内存,Python多线程存在 GIL 问题
方案:
- 协程
- gevent 模块
gevent.with_timeout(seconds=15, function=worker)
- 协程池
from gevent.pool import Pool
worker_poll = Pool(10) # 最大协程数 10