某电商网站一严重Bug的排查过程

字体大小: 中小 标准 ->行高大小: 标准

首先打开常用的top命令,不过这里我输入了shift+m指令,也就是让top里的进程列表按进程占用的内存从大到小排列。如下图

某电商网站一严重Bug的解决过程 (1)

这张图是在问题进程出现的时候截的,所以我们可以看到15149这个进程,图上显示占用的内存为144MB。
类似的进程每隔几分钟就会出现一次,占用内存从十几MB开始不断增加,直至达到memory_limit限制的数值,然后进程消失。

使用命令strace -p 15149,显示的内容如下图

某电商网站一严重Bug的解决过程 (2)

大概可以看出,程序在不断的查询数据库,仿佛进入了死循环。查询的表名为user,应该是在做和用户信息有关的操作,这条信息在后面会派上用场。

使用命令lsof -p 15149,可以看到下面这些信息

某电商网站一严重Bug的解决过程 (3)某电商网站一严重Bug的解决过程 (4)

根据图片显示的信息,可以判断进程正在处理的程序位于360cps目录下。并且,访问这个程序页面的IP为123.*.*.*。

然后根据这个IP地址去检查日志文件,如下图

某电商网站一严重Bug的解决过程 (5)

现在已经清楚了,出现问题的程序页面地址为api_redirect.php。

这家团购网站大部分流量是来自于tuan.360.cn,访客在360网站点击链接后,会打开一个360网站上的程序,这个程序会POST请求本网站的api_redirect.php,请求成功后才会跳转到本网站。

由于请求的方式为POST,而日志里没有办法记录POST的内容,所以,我修改了程序的代码,让程序记录POST数据。如下图。

某电商网站一严重Bug的解决过程 (6)

采集到的POST数据大概分为二种样本,
第一种:

某电商网站一严重Bug的解决过程 (7)

第二种: 某电商网站一严重Bug的解决过程 (8)

这二者的区别为,第一种是没有在360网站登录的,第二种是在360网站登录过的(有qid和qname,q应该是qihoo的意思)。
而在重复多次前面的检查方式后发现,出现问题的请求,都是在360网站登录过的访客。

已经收集到了足够多的信息,接下来开始审查程序。按程序的执行流程,从头开始看,发现了一处会涉及到用户表的操作(在前面已经通过strace跟踪到进程是在操作user表时出的问题),如下图。

某电商网站一严重Bug的解决过程 (9)

这个是只有在360网站登录过(有qid)才能进行的操作,从逻辑来看,符合收集到的POST数据后的判断(只有在360网站登录过的访客请求才会出问题)。

继续查找login_auto这段代码,如下图,这里只帖出关键部分

某电商网站一严重Bug的解决过程 (10)

前面我们已经看到,login_auto使用了360网站POST过来的mail地址作为参数,而从我们收集到的POST数据来看,这个mail地址是空的。

所以login_auto方法里赋给$cpsuser_mail这个变量的值就成了类似’_xxxxx’的样子。
我们到数据库去看一下

某电商网站一严重Bug的解决过程 (11)

可以看到,这样的地址已经排到了快10万个。
也就是说,现在的情况下,这段程序要检查数据库近10万次,才会跳出这个循环,已经和死循环差不多了。

到这里,问题已经完全弄清楚了,接下来的修复工作就简单多了,这里不再作描述。

这个Bug造成的危害十分严重,第一,所有在360登录过的用户都无法跳转到本站,造成大量的流量丢失,对于电商网站,流量就等于$。第二,进程出问题的时候会导致占用大量的内存和CPU,所以,在流量稍大的时候,很容易把服务器拖挂,在接手这个网站时老板曾提到过在双11等活动期间网站频频当机(后来了解到,这个接口已经用了二年多的时间)。

如果只看问题,其实很容易解决。难的是发现问题在哪里。

此文章由 http://www.ositren.com 收集整理 ,地址为: http://www.ositren.com/htmls/68060.html