☰

Ubuntuサーバー上で私のプロセスにSIGKILLを送信するのは誰ですか？質問する

tag-icon • tag-icon java c linux ubuntu java-native-interface
Ubuntuサーバー上で私のプロセスにSIGKILLを送信するのは誰ですか？質問する

10月25日の更新:

問題の原因が分かりました。

1) 子プロセスが自身を強制終了するため、strace/perf/auditctl では追跡できません。

2) プロセスを作成するための JNI 呼び出しは、Java スレッドからトリガーされます。スレッドが最終的に終了すると、作成したプロセスも破棄されます。

3) 子プロセスをフォークして execve() するコードに、親プロセスの終了を監視し、次の行で子プロセスを強制終了するコードがあります: prctl( PR_SET_PDEATHSIG, SIGKILL ); 子プロセスがメイン スレッドからフォークされる他のプロジェクトではこれがベスト プラクティスと見なされているため、これまでこのフラグに特別な注意を払わなかったのは私の責任です。

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日の更新:

たくさんのご提案をいただき、本当にありがとうございます。システムの 1 つの領域から別の領域まで調査中です。原因を見つけるのは難しいです。

2 つの点について疑問に思っています。1) strace、auditctl、perf スクリプトなどの強力なツールでは、誰が kill を実行したのかを追跡できないのはなぜでしょうか?

2) +++ が SIGKILL +++ によって強制終了されるというのは、実際にはシグナルによって強制終了されることを意味しますか?

オリジナル投稿

Ubuntu 12 の Java アプリケーション サーバーから JNI インターフェイスを介して起動された、長時間実行される C プロセスがあります。Java のプロセス ビルダーではなく JNI インターフェイスを使用してプロセスを開始する理由は、パフォーマンス上の理由です。Java プロセス ビルダーが IPC を実行するのは非常に非効率的で、特に余分なバッファリングによって非常に長い遅延が発生します。

定期的に SIGKILL によって不可解に終了することがあります。私が発見した方法は strace で、次のように表示されます: "+++ は SIGKILL +++ によって終了しました"

以下のことを確認しました。

  1. それは事故ではありません。
  2. これは OOM ではありません。dmesg には何も表示されません。私のプロセスは 1G バイトのメモリの 3.3% しか使用しません。
  3. Java レイヤーはプロセスを強制終了しませんでした。コードがプロセスを終了する場合は JNI コードにログを配置しましたが、それを示すログは書き込まれませんでした。
  4. 権限の問題ではありません。sudo または別のユーザーとして実行しようとしましたが、どちらの場合もプロセスが強制終了されます。
  5. プロセスをシェル内でローカルに実行すると、すべて正常に動作します。さらに、長時間実行されるプロセスの C コードでは、シグナル SIGHUP を無視します。Java サーバーの子プロセスとして実行されている場合にのみ、強制終了されます。
  6. このプロセスは CPU を非常に集中的に使用します。CPU の 30% を使用しています。自発的なコンテキスト スイッチと非自発的な ctxt スイッチが多数あります。
  7. (新しい更新) プロセスが強制終了される理由に関係している可能性が高い重要な点が 1 つあります。プロセスが重い処理を行っている場合は強制終了されませんが、CPU を集中的に使用する作業が少し行われている場合もあります。その場合、しばらくして (約 1 分後)、強制終了されます。ステータスは常に R (実行中) ではなく S (スリープ中) です。OS は、プロセスがほとんどの時間アイドル状態だった場合はプロセスを強制終了し、ビジー状態の場合はプロセスを強制終了しないことにしているようです。
  8. Java の GC が原因だと疑っていますが、Java は JNI に関連付けられたシングルトン オブジェクトを決してガベージ コレクションしません (私の JNI オブジェクトはそのシングルトンに関連付けられています)。

なぜ終了したのか理由がわかりません。追跡方法について良い提案をお持ちの方はいらっしゃいますか?

追伸

  1. 私の Ubuntu limit -a の結果は次のとおりです:

    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

  2. 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

  3. 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 +++

ベストアンサー1

マシン上でルートアクセス権を持っていると仮定すると、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)

もう 1 つの方法はカーネル トレースを設定することですが、監査システムで同じ作業を実行できる場合は、これはやり過ぎになる可能性があります。

おすすめ記事