ОБНОВЛЕНИЯ от 25 октября:
Теперь я выяснил, что вызывает проблему.
1) Детский процесс убивает себя, поэтому strace/perf/auditctl не может отследить его.
2) JNI-вызов для создания процесса запускается из потока Java. Когда поток в конечном итоге умирает, он также разрушает процесс, который он создает.
3) В моем коде fork и execve() дочерний процесс, у меня есть код для отслеживания смерти родительского процесса и уничтожения моего дочернего процесса со следующей строкой: prctl (PR_SET_PDEATHSIG, SIGKILL); Моя вина, что я не обращал особого внимания на этот флаг, прежде чем он/она рассмотрит как ЛУЧШУЮ ПРАКТИЦИЮ для моих других проектов, где дочерний процесс разветвляется из основного потока.
4) Если я прокомментирую эту строку, проблема исчезнет. Первоначальная цель - убить дочерний процесс, когда родительский процесс исчез. Даже без этого флага все еще правильное поведение. Похоже на поведение по умолчанию в ядре ubuntu.
5) Наконец-то найденная ошибка ядра, исправленная в версии ядра 3.4.0, ящик Ubuntu от AWS является версией ядра 3.13.0-29-generic.
Есть несколько полезных ссылок на проблемы:
a) http://www.linuxprogrammingblog.com/threads-and-fork-think-twice-before-using-them
c) https://bugzilla.kernel.org/show_bug.cgi?id=43300
ОБНОВЛЕНИЯ 15 октября:
Большое спасибо за все предложения. Я исследую из одной области системы в другую область. Трудно найти причину.
Мне интересно 2 вещи. 1) почему мощные инструменты, такие как strace, auditctl и perf script не способны отслеживать, кто вызвал убийство?
2) Является ли +++, убитым SIGKILL +++, действительно означает его убитый из сигнала?
ОРИГИНАЛЬНАЯ ПОЧТА
У меня длительный процесс C, запущенный с сервера приложений Java в Ubuntu 12 через интерфейс JNI. Причина, по которой я использую интерфейс JNI для запуска процесса, а не через Java-процесс, - это b/c из соображений производительности. Это очень неэффективно для java process builder для IPC, особенно b/c, дополнительная буферизация вводит очень долгую задержку.
Периодически он прерывается SIGKILL таинственным образом. То, как я узнал, - это strace, в котором говорится: "+++ убито SIGKILL +++"
Я проверил следующее:
- Это не крушение.
- Это не OOM. Ничего в dmesg. Мой процесс использует только 3,3% 1 Гбайт памяти.
- Уровень Java не убил процесс. Я помещаю журнал в код JNI, если код завершает процесс, но для этого не было записано ни одного журнала.
- Это не проблема разрешения. Я пытался работать как sudo или другой пользователь, оба случая заставляют процесс быть убитым.
- Если я запускаю процесс локально в оболочке, все работает нормально. Что еще, в моем C-коде для моего долговременного процесса, я игнорирую сигнал SIGHUP. Только когда он работает как дочерний процесс Java-сервера, он убивается.
- Процесс очень интенсивен. Он использует 30% процессора. Существует множество добровольных переключателей контекста и nonvoluntary_ctxt_switches.
- (НОВОЕ ОБНОВЛЕНИЕ) Одна ВАЖНАЯ вещь очень вероятно связана с тем, почему мой процесс убит. Если процесс совершит тяжелый подъем, он не будет убит, однако иногда он делает небольшую работу с интенсивным процессором. Когда это произойдет, через некоторое время, примерно 1 мин, он будет убит. Это состояние всегда S (Спящий) вместо R (Бег). Кажется, ОС решила убить процесс, если он большую часть времени простаивал, а не убивать процесс, если он занят.
- Я подозреваю, что Java GC является виновником, однако Java никогда не будет мусором собирать одноэлементный объект, связанный с JNI. (Мой объект JNI привязан к этому синглтону).
Я озадачен причиной его прекращения. Кто-нибудь имеет хорошее предложение, как его отслеживать?
p.s.
-
В моем ограничении ubuntu -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
-
Вот статус proc, когда я запускаю cat/proc/$$$/status
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 +++