рабочий квест: php-oci8 && ORA-28002
Сбой в вверенном нам серверном хозяйстве происходит очень редко, но если уже случается.. то это порою квест не хуже всяких головоломок. Сегодня был как раз именно такой..
22:02 мониторинг начинает искриться и разрастаться красными красками аки ёлка в новогоднюю ночь.
Я получаю первые входные данные:
top - 15:05:57 up 188 days, 3:06, 5 users, load average: 433.20, 182.14, 69.66
Беглый анализ показал, что это apache начал свою бурную деятельность.. Но исследования, были не такие резвые, так как отзыв от сервера практически минутные.
Анализ графиков и сетевой активности через tcpdump предположение о DoS не подтверждают, но это была только первая идея.
Предприняли попытку рестарта killall -9 httpd. Ничего не киляет, а только переводит процесс в D state. И нагрузка начинает спадать только через какое то время (минут 10)
Попытки что-то ещё выяснить показывают дикую загрузку по IO:
avg-cpu: %user %nice %system %iowait %steal %idle
0.19 0.00 1.12 81.29 0.00 17.40
Device: tps Blk_read/s Blk_wrtn/s Blk_read Blk_wrtn
sda 95.00 68.00 74560.00 136 149120
sda1 0.00 0.00 0.00 0 0
sda2 0.00 0.00 0.00 0 0
sda3 95.00 68.00 74560.00 136 149120
Если такая дикая запись на диски есть, значит где-то должно прибавляться с местом. Только вот где ? Запуск du на папке /var/logs увалил в ступор машину ещё больше. Я пошёл искать на соседней консоле другие папки. И бинго!
[root@somehost tmp]# pwd
/tmp
[root@somehost tmp]# du -sh
82G .
Быстрый просмотр показал, что там 82G без мелочи coredump файлы от apache.. И сразу появилось подтверждение из сообщений в главном error_log apache от чего всё тормозит. Вообще надо было сразу туда смотреть, но как то пропустили этот момент (а могли бы минут 15 сэкономить) :(
[Mon Dec 27 16:55:11 2010] [notice] child pid 12644 exit signal Segmentation fault (11)
Из анализа coredump сходу вспоминается только bt в gdb который не сильно помог в этой ситуации
(gdb) core-file /tmp/core.8689
[New Thread 8689]
Core was generated by `/usr/sbin/httpd'.
Program terminated with signal 11, Segmentation fault.
#0 0x00002ba92d7603f1 in ?? ()
Выключил опцию CoreDumpDirectory. Нагрузка спала, но функционал мёртвый совершенно.
Начали трейсить php скрипты руками и бинго повторяется снова с первого скрипта:
read(4, "\1\t\0\0\6\0\0\0\0\0\10\2\0\f\0\0\0\fAUTH_SESSKEY@\0"..., 2064) = 265
getcwd("/root"..., 256) = 6
brk(0x1ba27000) = 0x1ba27000
write(4, "\2\237\0\0\6\0\0\0\0\0\3s\3\310I\235\33\0\0\0\0\3\0\0\0\1\201\0\0008\226s"..., 671) = 671
read(4, "\6\262\0\0\6\0\0\0\0\0\17bm2\0\4\0002ORA-28002: the"..., 2064) = 1714
fcntl(463430368, F_SETFD, FD_CLOEXEC) = -1 EBADF (Bad file descriptor)
fcntl(463431536, F_SETFD, FD_CLOEXEC) = -1 EBADF (Bad file descriptor)
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
(END)
Оказалось warning сообщение от oracle "ORA-28002: the password will expire within 7 days" несовместимы с жизней модуля oci в php.. Отчего у последнего срывало крышу и уносило далеко в /tmp...
Далее проблемма была спихнута в сторону DBA которому тоже достались все дополнительные пряники от начальства.
Полный downtime 2 часа. Если бы не тормоза системы, можно было бы сильно сократить исследования проблемы.
Кстати у _adept_ Начался новый квест http://users.livejournal.com/_adept_/111378.html спешите участвовать.
22:02 мониторинг начинает искриться и разрастаться красными красками аки ёлка в новогоднюю ночь.
Я получаю первые входные данные:
top - 15:05:57 up 188 days, 3:06, 5 users, load average: 433.20, 182.14, 69.66
Беглый анализ показал, что это apache начал свою бурную деятельность.. Но исследования, были не такие резвые, так как отзыв от сервера практически минутные.
Анализ графиков и сетевой активности через tcpdump предположение о DoS не подтверждают, но это была только первая идея.
Предприняли попытку рестарта killall -9 httpd. Ничего не киляет, а только переводит процесс в D state. И нагрузка начинает спадать только через какое то время (минут 10)
Попытки что-то ещё выяснить показывают дикую загрузку по IO:
avg-cpu: %user %nice %system %iowait %steal %idle
0.19 0.00 1.12 81.29 0.00 17.40
Device: tps Blk_read/s Blk_wrtn/s Blk_read Blk_wrtn
sda 95.00 68.00 74560.00 136 149120
sda1 0.00 0.00 0.00 0 0
sda2 0.00 0.00 0.00 0 0
sda3 95.00 68.00 74560.00 136 149120
Если такая дикая запись на диски есть, значит где-то должно прибавляться с местом. Только вот где ? Запуск du на папке /var/logs увалил в ступор машину ещё больше. Я пошёл искать на соседней консоле другие папки. И бинго!
[root@somehost tmp]# pwd
/tmp
[root@somehost tmp]# du -sh
82G .
Быстрый просмотр показал, что там 82G без мелочи coredump файлы от apache.. И сразу появилось подтверждение из сообщений в главном error_log apache от чего всё тормозит. Вообще надо было сразу туда смотреть, но как то пропустили этот момент (а могли бы минут 15 сэкономить) :(
[Mon Dec 27 16:55:11 2010] [notice] child pid 12644 exit signal Segmentation fault (11)
Из анализа coredump сходу вспоминается только bt в gdb который не сильно помог в этой ситуации
(gdb) core-file /tmp/core.8689
[New Thread 8689]
Core was generated by `/usr/sbin/httpd'.
Program terminated with signal 11, Segmentation fault.
#0 0x00002ba92d7603f1 in ?? ()
Выключил опцию CoreDumpDirectory. Нагрузка спала, но функционал мёртвый совершенно.
Начали трейсить php скрипты руками и бинго повторяется снова с первого скрипта:
read(4, "\1\t\0\0\6\0\0\0\0\0\10\2\0\f\0\0\0\fAUTH_SESSKEY@\0"..., 2064) = 265
getcwd("/root"..., 256) = 6
brk(0x1ba27000) = 0x1ba27000
write(4, "\2\237\0\0\6\0\0\0\0\0\3s\3\310I\235\33\0\0\0\0\3\0\0\0\1\201\0\0008\226s"..., 671) = 671
read(4, "\6\262\0\0\6\0\0\0\0\0\17bm2\0\4\0002ORA-28002: the"..., 2064) = 1714
fcntl(463430368, F_SETFD, FD_CLOEXEC) = -1 EBADF (Bad file descriptor)
fcntl(463431536, F_SETFD, FD_CLOEXEC) = -1 EBADF (Bad file descriptor)
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
(END)
Оказалось warning сообщение от oracle "ORA-28002: the password will expire within 7 days" несовместимы с жизней модуля oci в php.. Отчего у последнего срывало крышу и уносило далеко в /tmp...
Далее проблемма была спихнута в сторону DBA которому тоже достались все дополнительные пряники от начальства.
Полный downtime 2 часа. Если бы не тормоза системы, можно было бы сильно сократить исследования проблемы.
Кстати у _adept_ Начался новый квест http://users.livejournal.com/_adept_/111378.html спешите участвовать.