记录特殊情况的Python脚本的内存异常与处理

时间：2021-07-16 05:12:05

问题

Python 脚本使用 requests 模块做 HTTP 请求，验证代理 IP 的可用性，速度等。 设定 HTTP 请求的 connect timeout 与 read response timeout 均为 3 秒，allow_redirects 设定为 False。Linux shell 启动 10 个 Python 进程持续从 Redis 队列中读取数据。监控软件持续获取进程内存信息。多个小时之后出现，极个别进程内存占用量暴增，其余进程内存均处于正常且相等的水平。

脚本分析

猜测 Python 脚本出现内存过大问题的可能原因：

  1. 重复，相互引用
  2. 重复实例化
  3. 打开文件数量过多，并且未释放

针对上面猜测的检查方案：

  1. print 打印主函数中的每个对象，在 while 循环中，被引用的次数。结果：无重复引用。
  2. memory_profiler 与 objgraph 模块输出主函数内存使用情况，连续测试 10K 条IP，未发现内存爆增问题
  3. lsof 命令对比 异常进程与正常进程打开的文件对比，结果：打开文件相同，没有异常。

外部分析

外部分析工具：

  1. strace 跟进进程调用系统调用
  2. lsof 检查进程的开发的句柄，包括文件，网络连接等
  3. 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 的超时时间设定对此类问题均无效。

处理方案

思考：

  1. 由于是 TCP 层的连接问题，HTTP层的超时时间对此无效，需要外部对每次多 HTTP 连接作超时处理。
  2. 此脚本行为更多占用的系统 IO 而非 CPU 计算，多进程方案会占用很多内存，Python多线程存在 GIL 问题

方案：

  1. 协程
  2. gevent 模块
  3. gevent.with_timeout(seconds=15, function=worker)
  4. 协程池
from gevent.pool import Pool

worker_poll = Pool(10) # 最大协程数 10

相关文章