以前解决一个进程被杀死的问题后写的记录,略作修改,放这里做个记录。

故事是这么开始的:

某日,一用户现场系统出现故障,有时候会读取数据失败。经过简单的排查,很快开发同事找到原因:服务进程退出,并由systemd重启:

systemd: XXXX.service: main process exited, code=killed, status=9/KILL
systemd: Unit XXXX.service entered failed state.
systemd: XXXX.service failed.
systemd: XXXX.service holdoff time over, scheduling restart.

不过问题定位到这里就进行不下去了:进程被外部Kill -9 杀掉,并且不是因为OOM killer(内存利用率并不高,而且内核日志没有出现任何异常)。该问题一直搁置了一个月,直到最近我转到该组,领导说我在Linux下搞的问题比较多,把问题转给了我让我先研究研究。

一步一步去追寻真相

  1. 从syslog确认,进程是由外部Kill掉的(kill -9),且我对项目完全不熟悉,因此不考虑投入代码层面的分析。转头向操作系统索取信息。

  2. 众所周知,程序员一个重要的能力就是面向Google编程。同样解决Linux问题也要如此,首先我在StackOverflow搜索了Kill相关问题,得到重要提示:可以使用auditctl或者sysdig来捕获系统调用信息。

  3. audit!以前就了解过这个神器,但是却从来没有实战过,因此没什么印象。这时候不禁感叹:纸上得来终觉浅,绝知此事要躬行。

  4. 了解了audit基本用法,在出问题的环境上执行了如下命令来捕获进程退出的信息:

    1
    auditctl -a exit,always -S kill
  5. 幸运的是,这个问题复现概率还是挺高的,当天上午就出现了另一次进程被Kill,从对应的audit log中,找到了发出Kill命令的进程信息(xxxxxx是服务进程名字):

    type=SYSCALL msg=audit(1515310507.002:69421137): arch=c000003e syscall=62 success=yes exit=0 a0=1ed5ef a1=9 a2=0 a3=7ffc76676c60 items=0 ppid=2049521 pid=2049524 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=276169 comm=”sh” exe=”/usr/bin/bash” key=(null)
    type=OBJ_PID msg=audit(1515310507.002:69421137): opid=2020847 oauid=-1 ouid=167 oses=-1 ocomm=”xxxxxx”

第一行是发出调用命令的进程,第二行是被干掉的进程信息。

  1. 可惜的是,始作俑者已经找不到了,干坏事的进程已经不在了。不过audit还可以把新建进程的信息也记录下来,譬如:
    1
    auditctl -a task,always
    2
    ausearch -i -sc execve

7.再次等待罪犯下次露面之后,终于发现,是一个Crontab任务搞的鬼。这个定时任务每分钟执行一次,执行一个脚本,目的是找到一些僵尸进程并kill掉,可惜代码有bug,在某些条件下会误操作,kill掉正常的进程。

8.剩下的事情就简单了,交给运维去找背锅的人就好了。而我,收到了领导安排的另外Linux上服务异常的问题,大概是能者多劳吧 :D(虽然查了很多资料才搞定,感觉很有收获:P)

  1. 下一步要对sysdig audit这些能获取系统信息的神器好好做朋友。说不定哪天有需要他们帮忙了。