问题描述
10月25日的更新:
现在,我找出了导致问题的原因。
1)子进程杀死了自己,这就是strace /perf /auditctl无法对其进行跟踪的原因。
2)从Java线程触发创建流程的JNI调用。当线程最终死亡时,它也在破坏它创建的进程。
3)在我的分支和 execve()子进程的代码中,我具有监视父进程死亡并使用以下行杀死我的子进程的代码: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) is called on parent thread exit, not parent process exit。
c)https://bugzilla.kernel.org/show_bug.cgi?id=43300
10月15日的更新:
非常感谢您的所有建议。我正在研究从系统的一个区域到另一个区域。 2很难找到原因。
我想知道两件事。 1)为什么strace,auditctl和perf脚本之类的功能强大的工具无法跟踪导致杀戮的原因?
2)+++被SIGKILL杀死+++真的意味着它被信号杀死了吗?
原始帖子
我通过JNI接口从Ubuntu 12中的Java应用程序服务器启动了运行很长时间的C进程。我使用JNI接口而不是通过Java的流程生成器来启动流程的原因是出于性能方面的考虑。 Java进程构建器执行IPC的效率非常低,尤其是b /c额外的缓冲会导致很长的延迟。
周期性地,它会被SIGKILL神秘地终止。我发现的方法是通过strace,它说:“ +++被SIGKILL杀死+++”
我检查了以下内容:
-
这不是崩溃。
-
这不是OOM。没什么dmesg的。我的进程仅使用1Gbytes内存的3.3%。
-
Java层并未终止该过程。如果该代码终止了进程,我在JNI代码中放置了一个日志,但是没有写入任何日志来表明这一点。
-
这不是权限问题。我试图以sudo或其他用户身份运行,两种情况都导致进程被杀死。
-
如果我在Shell中本地运行该进程,则一切正常。而且,在long-running进程的C代码中,我忽略了信号SIGHUP。仅当它作为Java服务器的子进程运行时,它才会被杀死。
-
该过程占用大量CPU。它使用了30%的CPU。有很多自愿上下文切换和nonvoluntary_ctxt_switches。
-
(新更新)一件重要的事情很可能与为什么我的进程被杀死有关。如果该进程进行了一些繁重的工作,它不会被杀死,但是,有时它只在做很少的CPU密集型工作。发生这种情况后,大约一分钟后,它被杀死。它的状态始终为S(正在休眠),而不是R(正在运行)。似乎OS决定在大多数时间都处于空闲状态就终止该进程,而在忙碌时不终止该进程。
-
我怀疑Java的GC是元凶,但是Java绝不会垃圾收集与JNI相关的单例对象。 (我的JNI对象绑定到该单例)。
我对它终止的原因感到困惑。有谁有很好的建议如何进行追踪?
ps。
-
在我的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 +++
最佳方案
假设您具有计算机的root用户访问权限,则可以对kill(2)syscall启用审核以收集此类信息。
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)
另一种方法是设置内核跟踪,当审核系统可以执行相同的工作时,可以是over-kill。
次佳方案
如前所述,另一种选择是使用内核跟踪,这可以通过perf工具来完成。
# apt-get install linux-tools-3.13.0-35-generic
# perf list | grep kill
syscalls:sys_enter_kill [Tracepoint event]
syscalls:sys_exit_kill [Tracepoint event]
syscalls:sys_enter_tgkill [Tracepoint event]
syscalls:sys_exit_tgkill [Tracepoint event]
syscalls:sys_enter_tkill [Tracepoint event]
syscalls:sys_exit_tkill [Tracepoint event]
# perf record -a -e syscalls:sys_enter_kill sleep 10
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 1.634 MB perf.data (~71381 samples) ]
// Open a new shell to kill.
$ sleep 9999 &
[1] 2387
$ kill -9 2387
[1]+ Killed sleep 9999
$ echo $$
9014
// Dump the trace in your original shell.
# perf script
...
bash 9014 [001] 1890350.544971: syscalls:sys_enter_kill: pid: 0x00000953, sig: 0x00000009
第三种方案
最后,我弄清楚了原因。
子进程会杀死自己,这是一个Linux内核错误。
细节:
1)子进程杀死了自己,这就是strace /perf /auditctl无法对其进行跟踪的原因。
2)从Java线程触发创建流程的JNI调用。当线程最终死亡时,它也在破坏它创建的进程。
3)在我的分支和 execve()子进程的代码中,我具有监视父进程死亡并使用以下行杀死我的子进程的代码:prctl(PR_SET_PDEATHSIG,SIGKILL);在b /c被认为是我的其他项目(从主线程派生子进程)的其他项目的最佳实践之前,我没有特别注意此标志。
4)如果我注释掉这一行,问题就不存在了。最初的目的是在父进程消失后杀死子进程。即使没有此标志,它仍然是正确的行为。似乎是ubuntu框的默认行为。
5)从本文https://bugzilla.kernel.org/show_bug.cgi?id=43300。这是一个内核错误,已在3.4.0内核版本中修复,我从AWS来的ubuntu框是3.13.0-29-generic内核版本。
我的机器配置:===> Ubuntu 14.04 LTS ===> 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