近来一直在做部门疑难问题的排查工作,最近也准备在周分享上做一个小培训(交流)——“排查问题的方法和思路”。回想历史问题处理,觉得这是个很不错的案例,便回溯了一下排查过程记录下来。

一、问题背景

有一个应用层程序,依赖信号接收配置更新事件。

即程序依赖某个配置文件,当配置更新后,需要通过信号告知程序也做相应的更新。

番外故事篇

正常情况下,上面描述的这个机制是没有问题的。

直到有一天,测试同学跑来跟我说:“你的配置更新有bug”,这才结束了这美好的宁静。

虽然我本能的第一反应也是“傻逼你会用吗”,但是我还是假装很淡定的对他说:“bug发来看下”(实际上心里已经想好接下来要怎么怼他了)。然而,事出意料之外,竟然真的有bug,我亲手写出来的bug竟然真的不生效了????

二、排查过程

第一步,理清排查思路。排查的方向是信号为什么不生效,不生效可能是信号被屏蔽了,因此首先要确认的是信号状态。查看/proc/${pid}/status确认信号状态:

图中只列出了关键的几行,各行含义:

  • SigPng: 表示未决信号
  • SigBlk: 表示阻塞信号
  • SigIgn: 表示忽略信号
  • SigCgt: 表示已经捕获的信号

数值都是十六进制表示的数字,通过对比分析发现,SigIgn行刚好就有我通知更新的信号,说明进程屏蔽了信号。但是这怎么可能,代码中明明是需要捕获这个信号的,为什么在这里就被屏蔽了。

这里一度百思不得其解,没有什么思路继续排查。场景就像是,某天东西突然被偷了,但是没有监控,要找出偷东西的人。于是在经过了多轮精神折磨后,我选择了重启进程。

果然,重启后,问题解决了。然而,bug并没有解决,更恐怖的是,问题无法重现了!BUG根本没法查下去。

这也是一个教训,在测试环境下,有条件去查的时候,尽量不要重启服务,不然问题无法重现就麻烦了。

直到了N天后,测试决定放弃这个bug的时候,问题又重现了,但是测试也不知道是什么操作导致它重现的,它也是测试其他案例时候偶然发现功能又不生效的。这就大大增加了排查难度,前无因后无果,依旧无法下手。

没办法,捋清楚思路,继续往下查。先找两个环境对比信号状态,发现没问题的环境信号是没有被屏蔽,但是有问题的环境信号确实被屏蔽了。这说明,正常情况下程序肯定是没有问题的,一定是有某个外部操作导致了环境异常。

这时候,我的思路放在了是什么操作导致异常上,这也是大部分人都会考虑到的点。于是我通过最近一天的访问日志和历史操作日志来反推可能的操作,但是找了很长时间后,都没有定位到具体触发操作,范围实在是太大了。

。。。

直到一天过去后,我和测试同学才终于找到了触发问题的操作,触发的操作是在前端页面上同步了一下系统时间。因为环境刚启动的时候设备时间不对,测试同学手动同步了一下时间,这才产生了这个问题。

找到了触发条件后,问题就好查了,追踪代码流程,发现同步系统时间后,会把所有的服务重启。具体的流程为:

关键点就在于这重启服务上,我们的web服务是部署了一个apache,apache重启后台服务的时候导致它变成了所有服务的父进程。而创建子进程的时候,所有子进程都会继承父进程的信号屏蔽字,刚好apache就屏蔽了这个信号,导致所有被拉起的子进程都无法接受到这个信号。至此,问题的原因也就明了了。

解决方案

创建子进程后,通过信号集sigset_t相关的函数接口,清空子进程所有的信号屏蔽字。让子进程自己重新注册信号处理函数。

三、思路分析和总结

其实通过重启操作就能明显发现异常的地方是重启,因为重启之后没有现象了,说明问题肯定和重启相关。这个时候只要ps看一下进程状态,是不是被重启过了,再看一下父进程的pid就能大概发现问题了,而不用花大量的时间去定位重现操作。

总结:处理问题的思路太局限了,换个思路可能一下就查出来了,要善于抓住问题的关键点。

最后修改:2020 年 03 月 08 日
喜欢就给我点赞吧