谁在ubuntu服务器上神秘地向我的进程发送SIGKILL
10月25日更新:
现在我发现了导致问题的原因。
1)子进程会自我杀死,这就是为什么strace/perf/auditctl无法追踪它的原因。
2) 创建进程的 JNI 调用是从 Java 线程触发的。当线程最终死亡时,它也破坏了它创建的进程。
3)在我的代码中,我用于分叉和执行()子进程,我有代码来监视父进程死亡并杀死我的子进程,并使用以下行:prctl( PR_SET_PDEATHSIG,SIGKILL);我的错是,在b / c之前我没有特别注意这个标志,它被认为是我的其他项目的最佳实践,其中子进程是从主线程分叉的。
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) 在父线程退出时调用,而不是在父进程退出时调用。
c) https://bugzilla.kernel.org/show_bug.cgi?id=43300
10月15日更新:
非常感谢所有的建议。我正在从系统的一个区域到另一个区域进行调查。很难找到2个理由。
我想知道2件事。1)为什么strace,auditctl和perf脚本等强大的工具无法追踪谁造成了杀戮?
2)+++被SIGKILL +++杀死真的意味着它被信号杀死吗?
原文
我有一个长时间运行的C进程,通过JNI接口从Ubuntu 12中的Java应用程序服务器启动。我使用JNI接口而不是通过Java的进程构建器启动进程的原因是性能原因的b / c。对于java进程构建器来说,做IPC是非常低效的,特别是b / c额外的缓冲引入了很长的延迟。
它定期被SIGKILL神秘地终止。我发现的方式是通过strace,上面写着:“+++被SIGKILL +++杀死”
我检查了以下内容:
- 这不是崩溃。
- 它不是一个OOM。没有在 dmesg 中。我的进程仅使用 1GB 内存的 3.3%。
- Java层并没有杀死这个过程。如果代码终止了进程,我在JNI代码中放置了一个日志,但没有写入任何日志来指示这一点。
- 这不是权限问题。我试图以sudo或其他用户的身份运行,这两种情况都会导致进程被杀死。
- 如果我在 shell 中本地运行该进程,则一切正常。更重要的是,在我的长期运行的进程的C代码中,我忽略了信号SIGHUP。只有当它作为Java服务器的子进程运行时,它才会被杀死。
- 该过程非常占用 CPU 资源。它使用30%的CPU。有很多自愿的上下文切换和nonvoluntary_ctxt_switches。
- (新更新)一件重要的事情很可能与为什么我的进程被杀死有关。如果进程执行一些繁重的工作,它不会被杀死,但是,有时它很少执行CPU密集型工作。当这种情况发生时,一段时间后,大约1分钟,它就被杀死了。它的状态始终为 S(休眠)而不是 R(正在运行)。似乎操作系统决定在进程大部分时间都处于空闲状态时终止该进程,而在进程繁忙时不终止该进程。
- 我怀疑Java的GC是罪魁祸首,但是,Java永远不会垃圾收集与JNI关联的单例对象。(我的 JNI 对象与该单例绑定)。
我对它终止的原因感到困惑。有没有人有一个很好的建议如何追踪它?
附言
-
在我的 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 -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 +++