前段时间在查看线上服务器状态时,发现了一个奇怪的情况:top指令下,CPU占用率飙升到40+(不是0.4而是40),即使是线上8核的情况,每个核的排队进程数量也达到了500%;对于一个平常占用率不会超过0.4的系统而言,这一情况是极为诡异的。
一开始首先需要查看的是进程列表,查看到底是哪些进程占用了如此多的CPU;在top下按P键选择按CPU利用率逆序排序,观察到第一页内一个名为"checklistingerror"的进程几乎占用了所有的行(利用ps -ef | grep 'check_listing_error' | wc -l),而这一进程实际上是一个PHP格式的定时脚本,看名字大概是用来检查后台商品情况,标记错误的;大致就有了思路;
接下来就是根据进程名寻找对应的业务逻辑代码:进入到后台脚本代码中,找到该函数对应的代码片段,逐行阅读之;经检查,该函数的用途为遍历MongoDB中listing这一集合里的所有元素,根据指定规则检查是否出现错误,而这一过程中由于自定义的错误类型较多,故而单个listing的检查过程中,会出现多次读写表的操作;于是在这里思路开始清楚起来:在处理的过程中有一项操作较为耗时,故而产生了锁表的行为;而在一次脚本执行后由于没有退出,就执行了下一次批量检查的操作,故而每小时的这个函数执行循环阻塞;导致了连接MongoDB的连接数越来越多(且无法断开,由于都没有中止),从而CPU飙升到了极限;
明白这一操作后,开始找寻错误出现的场景:
最后追溯PHP的业务逻辑,找到这段查询的应用场景:原来在每次查询过程中,除了listing本身外,还会去另一张保留有listing的SKU合法性的表里去获取所有合法的SKU(即DISTINCT操作),而对每个listing的检查,由于都会进行一次distinct,所以自然速度就慢了下来;但是如果不是每次都进行distinct,而是只进行一次distinct的话,循环过程中的写入就不会被记录在这个”合法SKU集合“里,从而对后面的判断产生问题;所以在这一过程中,运用到了函数中static变量仅初始化一次的特性,将这次”取集合“的操作仅在函数第一次调用的时候执行,而后续循环过程中的写入,则调用这个函数,通过增加成员的方式($sku_listing[]= $new_sku)实现;一次循环后,果然表的延迟有一定的提升,但是仍然卡住了;
重新思考业务逻辑,观察代码,突然发现原来循环过程中的一个判断条件有误,导致每次循环的所有listing均会重新写表(合法SKU集合表),而对于几万行数据而言,重复的读写操作必然会产生大量的延迟(锁),这才是问题的关键;经修改,这一业务逻辑的bug被修复,重复执行后,线上恢复了正常
以上,与大家共享
掠影(萨秋)