java - 谁在 ubuntu 服务器上神秘地向我的进程发送了 SIGKILL

Question

10 月 25 日更新:

现在我发现了导致问题的原因。

1) 子进程自行杀死，这就是为什么 strace/perf/auditctl 无法追踪它。

2)创建进程的JNI调用是从Java线程触发的。当线程最终死亡时，它也会破坏它创建的进程。

3) 在 fork 和 execve() 子进程的代码中，我有代码来监视父进程死亡并使用以下行杀死我的子进程:prctl( PR_SET_PDEATHSIG, SIGKILL );我的错是我在 b/c 之前没有特别注意这个标志，它被认为是我的其他项目的最佳实践，其中子进程是从主线程 fork 的。

4)如果我注释掉这一行，问题就消失了。最初的目的是在父进程消失时杀死子进程。即使没有这个标志，它仍然是正确的行为。似乎是 ubuntu 框的默认行为。

5) 最后发现它是一个内核错误，在内核版本 3.4.0 中修复，我从 AWS 的 ubuntu 框是内核版本 3.13.0-29-generic。

这些问题有几个有用的链接:

a) http://www.linuxprogrammingblog.com/threads-and-fork-think-twice-before-using-them

b) prctl(PR_SET_PDEATHSIG, SIGNAL) is called on parent thread exit, not parent process exit .

c) https://bugzilla.kernel.org/show_bug.cgi?id=43300

10 月 15 日更新:

非常感谢所有的建议。我正在从系统的一个区域调查到另一个区域。很难 2 找到原因。

我想知道 2 件事。
1) 为什么strace、auditctl 和perf 脚本等强大的工具无法追查到谁导致了被杀？

2)+++ 被 SIGKILL+++ 杀死真的意味着它被信号杀死了吗？

原帖

我通过 JNI 接口(interface)从 Ubuntu 12 中的 Java 应用程序服务器启动了一个长时间运行的 C 进程。我使用 JNI 接口(interface)而不是通过 Java 的进程构建器来启动进程的原因是性能原因。 Java 进程构建器执行 IPC 的效率非常低，尤其是 b/c 额外缓冲引入了很长的延迟。

它会定期被 SIGKILL 神秘地终止。我发现的方法是通过strace，它说:“+++被SIGKILL+++杀死”

我检查了以下内容:

这不是崩溃。

这不是OOM。 dmesg 中没有任何内容。我的进程只使用了 1GB 内存的 3.3%。

Java 层没有终止进程。如果代码终止了进程，我会在 JNI 代码中写入日志，但没有写入日志来表明这一点。

这不是许可问题。我尝试以 sudo 或其他用户身份运行，这两种情况都会导致进程被终止。

如果我在 shell 中本地运行该进程，则一切正常。更重要的是，在我的长期运行进程的 C 代码中，我忽略了信号 SIGHUP。只有当它作为 Java 服务器的子进程运行时，它才会被杀死。

该过程非常占用 CPU。它使用了 30% 的 CPU。有很多自愿上下文切换和非自愿_ctxt_switches。

(新更新)一件重要的事情很可能与我的进程被杀死的原因有关。如果进程做了一些繁重的工作，它不会被杀死，但是，有时它只做很少的 CPU 密集型工作。当这种情况发生时，一段时间后，大约 1 分钟，它就会被杀死。它的状态总是 S(Sleeping) 而不是 R(Running)。似乎操作系统决定在大部分时间空闲时终止进程，如果进程繁忙则不终止进程。

我怀疑 Java 的 GC 是罪魁祸首，但是，Java 永远不会垃圾收集与 JNI 关联的单例对象。 (我的 JNI 对象绑定(bind)到那个单例)。

我对它被终止的原因感到困惑。有没有人有一个很好的建议如何追踪它？

附言

在我的 ubuntu 限制上 - 结果是:

core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 7862
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 65535
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 7862
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

我试图增加限制，但仍然没有解决问题。

core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) unlimited
max locked memory       (kbytes, -l) unlimited
max memory size         (kbytes, -m) unlimited
open files                      (-n) 65535
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) unlimited
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) unlimited
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

这是我运行 cat/proc/$$$/status 时的 proc 状态

Name:   mimi_coso
State:  S (Sleeping)
Tgid:   2557
Ngid:   0
Pid:    2557
PPid:   2229
TracerPid:  0
Uid:    0   0   0   0
Gid:    0   0   0   0
FDSize: 256
Groups: 0
VmPeak:   146840 kB
VmSize:   144252 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:     36344 kB
VmRSS:     34792 kB
VmData:    45728 kB
VmStk:       136 kB
VmExe:       116 kB
VmLib:     23832 kB
VmPTE:       292 kB
VmSwap:        0 kB
Threads:    1
SigQ:   0/7862
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000004
SigIgn: 0000000000011001
SigCgt: 00000001c00064ee
CapInh: 0000000000000000
CapPrm: 0000001fffffffff
CapEff: 0000001fffffffff
CapBnd: 0000001fffffffff
Seccomp:    0
Cpus_allowed:   7fff
Cpus_allowed_list:  0-14
Mems_allowed:   00000000,00000001
Mems_allowed_list:  0
voluntary_ctxt_switches:    16978
nonvoluntary_ctxt_switches: 52120

strace 显示:

$ strace -p 22254 -s 80 -o /tmp/debug.lighttpd.txt
read(0, "SGI\0\1\0\0\0\1\0c\0\0\0\t\0\0T\1\2248\0\0\0\0'\1\0\0(\0\0"..., 512) = 113
read(0, "SGI\0\1\0\0\0\1\0\262\1\0\0\10\0\1\243\1\224L\0\0\0\0/\377\373\222D\231\214"..., 512) = 448
sendto(3, "<15>Oct 10 18:34:01 MixCoder[271"..., 107, MSG_NOSIGNAL, NULL, 0) = 107
write(1, "SGO\0\0\0\0 \272\1\0\0\t\0\1\253\1\243\273\0\0\0\0'\1\0\0\0\0\0\1\242"..., 454) = 454
sendto(3, "<15>Oct 10 18:34:01 MixCoder[271"..., 107, MSG_NOSIGNAL, NULL, 0) = 107
write(1, "SGO\0\0\0\0 \341\0\0\0\10\0\0\322\1\254Z\0\0\0\0/\377\373R\4\0\17\21!"..., 237) = 237
read(0, "SGI\0\1\0\0\0\1\0)\3\0\0\t\0\3\32\1\224`\0\0\0\0'\1\0\0\310\0\0"..., 512) = 512
read(0, "\344u\233\16\257\341\315\254\272\300\351\302\324\263\212\351\225\365\1\241\225\3+\276J\273\37R\234R\362z"..., 512) = 311
read(0, "SGI\0\1\0\0\0\1\0\262\1\0\0\10\0\1\243\1\224f\0\0\0\0/\377\373\222d[\210"..., 512) = 448
sendto(3, "<15>Oct 10 18:34:01 MixCoder[271"..., 107, MSG_NOSIGNAL, NULL, 0) = 107
write(1, "SGO\0\0\0\0 %!\0\0\t\0\0+\1\243\335\0\0\0\0\27\0\0\0\0\1B\300\36"..., 8497) = 8497
sendto(3, "<15>Oct 10 18:34:01 MixCoder[271"..., 107, MSG_NOSIGNAL, NULL, 0) = 107
write(1, "SGO\0\0\0\0 \341\0\0\0\10\0\0\322\1\254t\0\0\0\0/\377\373R\4\0\17\301\31"..., 237) = 237
read(0, "SGI\0\1\0\0\0\1\0\262\1\0\0\10\0\1\243\1\224\200\0\0\0\0/\377\373\222d/\200"..., 512) = 448
sendto(3, "<15>Oct 10 18:34:01 MixCoder[271"..., 107, MSG_NOSIGNAL, NULL, 0) = 107
write(1, "SGO\0\0\0\0 \341\0\0\0\10\0\0\322\1\254\216\0\0\0\0/\377\373R\4\0\17\361+"..., 237) = 237
read(0, "SGI\0\1\0\0\0\1\0\221\0\0\0\t\0\0\202\1\224\210\0\0\0\0'\1\0\0P\0\0"..., 512) = 159
read(0,  unfinished ...)

+++ killed by SIGKILL +++

Answer 1

假设您在您的机器上拥有 root 访问权限，您可以启用对 kill(2) 系统调用的审计来收集此类信息。

root # auditctl -a exit,always -F arch=b64 -S kill -F a1=9
root # auditctl -l
LIST_RULES: exit,always arch=3221225534 (0xc000003e) a1=9 (0x9) syscall=kill

root # sleep 99999 &
[2] 11688
root # kill -9 11688

root # ausearch -sc kill
time->Tue Oct 14 00:38:44 2014
type=OBJ_PID msg=audit(1413272324.413:441376): opid=11688 oauid=52872 ouid=0 oses=20 ocomm="sleep"
type=SYSCALL msg=audit(1413272324.413:441376): arch=c000003e syscall=62 success=yes exit=0 a0=2da8 a1=9 a2=0 a3=0 items=0 ppid=6107 pid=6108 auid=52872 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsg
id=0 tty=pts2 ses=20 comm="bash" exe="/bin/bash" key=(null)

另一种方法是设置内核跟踪，当审计系统可以做同样的工作时，这可能是一种过度杀伤。