---

---

引言

前段时间在查看线上服务器状态时，发现了一个奇怪的情况：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飙升到了极限；

• 明白这一操作后，开始找寻错误出现的场景：

  • 查找mongo中占用耗时最大的操作：db.currentOp()，打印出当前执行的表查询操作，并选择出running_secs > 3的所有操作来逐一遍历；这一过程中找到了一条$or作为筛选条件的find()命令，怀疑与它有关；
  • 退出MongoDB，利用自带的mongotop指令，查看当前哪些表耗时最多，果然和上一步中的find()命令重合，故而确定这次查询就是本次查询阻塞的罪魁祸首；
  • 记录下这个查询的条件，返回到代码里，找到对应的PHP查询代码

• 最后追溯PHP的业务逻辑，找到这段查询的应用场景：原来在每次查询过程中，除了listing本身外，还会去另一张保留有listing的SKU合法性的表里去获取所有合法的SKU（即DISTINCT操作），而对每个listing的检查，由于都会进行一次distinct，所以自然速度就慢了下来；但是如果不是每次都进行distinct，而是只进行一次distinct的话，循环过程中的写入就不会被记录在这个”合法SKU集合“里，从而对后面的判断产生问题；所以在这一过程中，运用到了函数中static变量仅初始化一次的特性，将这次”取集合“的操作仅在函数第一次调用的时候执行，而后续循环过程中的写入，则调用这个函数，通过增加成员的方式（$sku_listing[]= $new_sku)实现；一次循环后，果然表的延迟有一定的提升，但是仍然卡住了；

• 重新思考业务逻辑，观察代码，突然发现原来循环过程中的一个判断条件有误，导致每次循环的所有listing均会重新写表（合法SKU集合表），而对于几万行数据而言，重复的读写操作必然会产生大量的延迟（锁），这才是问题的关键；经修改，这一业务逻辑的bug被修复，重复执行后，线上恢复了正常

总结

• 线上调优，首先需要找到问题的关键：本次事件中，问题关键就在于进程数量的积累，导致MongoDB连接数爆炸，从而CPU占用飙升；而找对了这一问题，接下来才有处理的可能性
• 对于涉及数据库的问题，首先要找到的是引起问题的表和操作：本次事件中，通过了mongotop这一内置指令来找到了读写延迟较大的表，缩小了目标范围；同时通过db.currentOp()的筛选器找到了每次执行时间较长的语句；而这种做法在MySQL中可以通过slow_query.log(慢查询日志)来解决，通过设置慢查询的标准，将所有执行耗时较大的语句都输出到这一日志中; 以及show processlist与show status来实现状态的查询
• 对于一些变化不大且需要频繁使用的数据，可以考虑将其设为函数静态变量，每次调用时不需要重复初始化其中数据，而仅在写入更新时改变其值即可；本例中用了PHP内置的特性，实际上也可以通过外部缓存的机制来运行，如借助Redis，Memcache等；
• 对一些逻辑问题导致的调优问题，特别是涉及复杂逻辑场景的，最好事先写好单元测试，并在本地执行后再上线；否则很有可能线上环境下会产生难以估计的问题；

以上，与大家共享

掠影（萨秋）

---

---

评论区

发表