search

tony2001 / pinba_extension

Pinba PHP extension
http://pinba.org
GNU Lesser General Public License v2.1
83 stars 22 forks source link

PHP-FPM's losts childs and consumes CPU with Pinba extension enabled #15

Closed validname closed 10 years ago

validname commented 10 years ago

(I'm sorry for using Russian language, I just want to make sure that I describe all precisely. And I hope you respond on this issue anyway. But I can translate it to English by your first request.)

У нас есть две проблемы, касающиеся связки PHP-FPM 5.4.21 + pinba extension. До этого мы без проблем использовали PHP-FPM 5.3.x + extension v.0.0.6, но затем "проапгрейдились". Обе проблемы связаны со временем работы PHP-чайлда:

  1. в логах PHP есть записи "PHP Fatal error: Maximum execution time of 30 seconds exceeded" (php.ini: max_execution_time = 30).
  2. чайлды PHP-FPM остаются работать и "выедать" по 1-му ядру CPU, но FPM их не "замечает" - в логах PFM есть только старт чайлда. Но когда мы убиваем чайлд руками, появляется запись "child ... exited on signal 15 (SIGTERM)". (php-fpm.conf: request_terminate_timeout = 31s)

Что удалось установить:

  1. Проблемы не зависит от версии pinba extension: я пробовал и 1.0.0 и 1.1.0 и последний коммит и даже версию 0.0.6 (+ commit, чтобы собиралось под 5.4).
  2. Проблемы не зависят от выполняемых скриптов, их имена случайны, а частота проявления проблемы на каждом скрипте зависит от частоты его запуска. Более того, может зависнуть даже скрипт с единственной строкой: "phpinfo()".
  3. Списки подвисших чайлдов и чайлдов, пожаловавшихся на 'Maximum execution time' не совпадают.
  4. Проблемы полностью исчезают, если выставить pinba.enabled=0.

Я собрал и запустил комплект из debug'овой версии PHP-FPM и всех extension'ов, но он работает нормально.

В относительных цифрах проблемы проявляется нечасто: всего 0,005% от общего числа запросов. Но в абсолютных цифрах мы имеем порядка 400 не отработавших скриптов в сутки. Плюс, источник этих проблем - неизвестен и это нервирует: вдруг проблема насчет проявляться чаще?

Можете ли Вы подсказать, куда двигаться дальше, чтобы найти источник проблемы?

tony2001 commented 10 years ago

Надо понять где конкретно оно уходит в себя. Лучше всего будет дождаться, когда проблема еще раз воспроизведется, и прицепиться к этому процессу GDB: gdb attach <pid процесса> после этого наберите bt full и пришлите мне вывод.

validname commented 10 years ago

Антон, спасибо большое за быстрый ответ! Вот backtrace зависшего процесса (который полностью "ест" 1 ядро):

(gdb) bt full

0 0x00007f1c7690f6dd in ?? () from /data/soft/php54/lib/php/extensions/no-debug-non-zts-20100525/pinba.so

No symbol table info available.

1 0x00000000007784bb in ?? ()

No symbol table info available.

2 0x0000000000679a6e in sapi_send_headers ()

No symbol table info available.

3 0x0000000000603b19 in php_header ()

No symbol table info available.

4 0x00000000006819bc in ?? ()

No symbol table info available.

5 0x0000000000681be8 in php_output_deactivate ()

No symbol table info available.

6 0x000000000066f515 in php_request_shutdown ()

No symbol table info available.

7 0x00000000007798a3 in ?? ()

No symbol table info available.

8 0x00007f1c7b9a8c4d in __libc_start_main () from /lib/libc.so.6

No symbol table info available.

9 0x000000000042fb89 in _start ()

No symbol table info available.

tony2001 commented 10 years ago

Ага, спасибо. А с этим коммитом тоже пробовали? https://github.com/tony2001/pinba_extension/commit/b87958222c71850bb902ba58e9d619d1e97ddece Я как раз это и исправлял. И у нас, судя по всему, всё исправилось.

Вообще-то, правильнее даже будет по-другому исправить. Вот такой патч можете попробовать: https://gist.github.com/tony2001/8397919 ?

validname commented 10 years ago

(моя вина: когда разбирался с проблемой, Вашего коммита еще не было, а вчера не проверил).

Собрал два exstension (последний коммит и тоже самое + патч), поставил на тест.

validname commented 10 years ago

сутки прошли - на тестах полёт нормальный. Поставлю на production вариант с добавочным патчем, в пятницу отпишусь.

validname commented 10 years ago

Антон, всё нормально, сейчас проблем нет. Спасибо за помощь!