Python实战2-Python脚本同一时间假死可能原因分析

4591566

　　背景：服务器跑Python脚本收集交易日志，发送到后台分析并存储到cassanda数据库
　　现象：某一不确定时间，脚本会假死（进程并没有停），实际已经不干活了，也不打日志，并且所有服务器的脚本都几乎同一时间假死，怎会如此一致呢？
　　分析：
　　一、检查脚本
　　1）发现脚本日志总是在出现若干次的Connection异常后，进程会假死
　　异常1：<urlopen error [Errno 104] Connection reset by peer>
　　说明：常见的有几种情况，1、服务器的并发连接数超过了最大值，服务器会将该连接关闭 ；2、客户关闭请求，而服务器还在给客户端发送数据
　　【reset日志】
　　2013-02-01 15:11:25,897 logtail.py [line:49] [INFO] worker:ORDER_SUCCESS,job is waiting...
　　2013-02-01 15:11:30,895 logtail.py [line:60] [INFO] worker:ORDER_SUCCESS,start job at 2013-02-02 15:11:30
　　2013-02-01 15:11:30,896 jobworker.py [line:161] [INFO] collect...
　　2013-02-01 15:11:30,911 jobworker.py [line:179] [INFO] send...
　　2013-02-01 15:11:30,912 jobworker.py [line:45] [INFO] http://110.75.14.162:8000/wirelesscrm/log/insertLog.do
　　2013-02-01 15:11:30,914 jobworker.py [line:52] [ERROR] <urlopen error [Errno 104] Connection reset by peer>
　　2013-02-01 15:11:30,914 jobworker.py [line:134] [INFO] ok=0, notok=1, sum=19
　　2013-02-01 15:11:30,930 logtail.py [line:67] [INFO] worker:ORDER_SUCCESS,job is done at 2013-02-02 15:11:30
　　异常2： <urlopen error [Errno 110] Connection timed out>
　　说明：最大可能性也是连接数太少，还有后台响应太慢，但服务器都很正常，也没有发布或重启
　　【timeout日志】
　　2013-02-01 15:11:35,928 logtail.py [line:60] [INFO] worker:ORDER_SUCCESS,start job at 2013-02-02 15:11:35
　　2013-02-01 15:11:35,928 jobworker.py [line:161] [INFO] collect...
　　2013-02-01 15:11:35,943 jobworker.py [line:179] [INFO] send...
　　2013-02-01 15:11:35,945 jobworker.py [line:45] [INFO] http://110.75.14.162:8000/wirelesscrm/log/insertLog.do
　　2013-02-01 15:14:44,944 jobworker.py [line:52] [ERROR] <urlopen error [Errno 110] Connection timed out>
　　2013-02-01 15:14:44,944 jobworker.py [line:134] [INFO] ok=0, notok=1, sum=25
　　2013-02-01 15:14:44,959 logtail.py [line:67] [INFO] worker:ORDER_SUCCESS,job is done at 2013-02-02 15:14:44
　　2）修改脚本，通过日志可以看到一个线程运行了有3分钟的时间，因此脚本设置连接超时时间，f = urllib2.urlopen(url, timeout=1)，设置为1s，在1台机器上运行了几天，经过观察，暂未发现上面的异常日志。
　　二、检查后台系统wcrm的apache配置，貌似找到了原因
　　apache的配置如下：
　　ServerTokens Prod
　　ServerSignature Off
　　Timeout 45
　　KeepAlive On
　　MaxKeepAliveRequests 20
　　KeepAliveTimeout 3
　　SendBufferSize 640000
　　说明：KeepAlive On是开启KeepAlive支持，KeepAliveTimeout决定一 个KeepAlive的连接能保持多少时间，Timeout后就关闭连接，若还有数据必须再建立新的连接 了，MaxKeepAliveRequests是最多服务多少个请求就关闭连接。显然这里设置的连接数20太少，但一般后台也没什么人用，然后再看apache日志，存在大量的自检请求，这样一来，确实没有多少连接可用了。。。
　　【apache日志】
　　72.24.90.154 541 - [02/Feb/2013:19:50:23 +0800] "GET http://172.24.53.113/crm/status.taobao" 200 - "-" "KeepAliveClient"
　　总结：为什么脚本同一时间停止的原因终于找到了，crm线上只有2台机器，交易服务器则有n多台，在某个时间当连接数不够用时，这样后面的请求都会失败，而所有机器的脚本线程一直处于等待响应状态，抛出异常后http资源没有释放（为什么没释放，是什么情况？？这里需要深入了解一下），增加关闭http资源代码：response = urllib2.urlopen(req,timeout=10)  response.close()