"завис" fpm

Dovg

Продвинутый новичок
Добрый день!

Исходные данные:

На всех серверах одинаковая операционка - debian stable
Код:
uname -a
Linux kley 2.6.26-2-amd64 #1 SMP Thu Nov 5 02:23:12 UTC 2009 x86_64 GNU/Linux
Выделенный фронт
Код:
/usr/sbin/nginx -v
nginx version: nginx/0.7.65
Несколько бекендов на fpm.
Часть проектов имеет в качестве бекендов только один сервер, часть - размазана ровным слоем по "ферме"

На бекендах такая конфигурация:
Код:
php -v
PHP 5.3.3-1 with Suhosin-Patch (cli) (built: Aug 17 2010 11:59:48) 
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.3.0, Copyright (c) 1998-2010 Zend Technologies
Код:
 cat /etc/php5/fpm/main.conf | grep -vE '^;' | uniq

[global]
pid = /var/run/php5-fpm.pid

error_log = /var/log/php5-fpm.log

include=/etc/php5/fpm/pool.d/*.conf
Вот один из пулов
Код:
cat /etc/php5/fpm/pool.d/plus1.conf 
[plus1]

listen = 0.0.0.0:9801

user = nobody
group = nogroup

pm = dynamic
pm.max_children = 164
pm.start_servers = 10
pm.min_spare_servers = 10
pm.max_spare_servers = 20
pm.max_requests = 1000
 
request_terminate_timeout = 0
request_slowlog_timeout = 1
slowlog = /var/log/php-fpm.log.slow
rlimit_files = 1024
rlimit_core = 0
catch_workers_output = yes
 
env[HOSTNAME] = $HOSTNAME
env[PATH] = /usr/bin:/bin
env[TMP] = /tmp
env[TMPDIR] = /tmp
env[TEMP] = /tmp

php_admin_value[sendmail_path] = /usr/sbin/sendmail -t -i -f [email protected]
php_flag[display_errors] = off
php_admin_value[error_log] = /var/log/fpm-php.proxy.log
php_admin_flag[log_errors] = on
php_admin_value[memory_limit] = 128M
php_admin_value[max_execution_time] = 10
php_admin_value[max_input_time] = 60
php_admin_value[expose_php] = off
Симптомы проблемы:
Нагрузка на одном из серверов внезапно и очень быстро упала с положенных la 6-8 до смешных 0.5
Проекты, бекенд которых жил только на этом сервере, перестали отвечать извне.
Причем отваливались по таймауту nginx, а не сразу.
ps aux | grep fpm показывал вполне живущих деток, причем в top они не попадали. У всех был статус S.
Было ощущение, что fpm принимал соединение, но ничего не делал.
Если бы он был просто выключен, то я бы увидел 504 сразу.

Решать проблему надо было оперативно, поэтому толком ничего посмотреть не смог.
Вылечилось так: sudo invoke-rc.d php5-fpm reload

Уже потом в slow_log я обнаружил вот это:
Код:
Jan 26 20:05:53.645078 [pool plus1] pid 13144
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php

Jan 26 20:05:53.645162 [pool plus1] pid 13151
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php
[0x00000000031de628] +++ dump failed

Jan 26 20:05:53.645241 [pool plus1] pid 13203
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php
[0x00000000030f0ab8] +++ dump failed

Jan 26 20:05:53.775811 [pool plus1] pid 13024
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php

Jan 26 20:05:53.775961 [pool plus1] pid 13025
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php

Jan 26 20:05:53.776162 [pool plus1] pid 13085
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php

Jan 26 20:05:53.776227 [pool plus1] pid 13114
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php

Jan 26 20:05:53.776288 [pool plus1] pid 13159
script_filename = /var/www/plus1.wapstart.ru/plus1/src/rotator/index.php
Никакого трейса к ним нет.
Все записи slow-log выше и ниже "проблемы" имеют вполне осмысленный трейс, что ожидаемо.


Вопросы:
Что произошло и как этого избежать?
Если виновато приложение, то почему "зависли" все пулы, а не один? Зависли точно все, иначе бы la не снизился так сильно. Извне это было не видно, т.к. умный nginx перераспределил нагрузку на другие сервера.

Если нужно какие-то еще данные, с радостью предоставлю.

ps. Опыт работы с fpm у меня очень небольшой. До него мы использовали /usr/bin/php -b ...
 

DiMA

php.spb.ru
Команда форума
У нас было такое, периодически подвисало и отвисало. Оказалась банальная причина - висит мемкеш (иногда тоже бывает, если какая-то таблица в sql посыпалась), далее висят пхп потоки и кажется, что во всем виноват крайний - пхпфпм. Разумеется, перезапуск phpfpm лечит ситуацию, убивая зависшие коннекты. Но источник проблемы остается.
 

Dovg

Продвинутый новичок
У нас было такое, периодически подвисало и отвисало. Оказалась банальная причина - висит мемкеш (иногда тоже бывает, если какая-то таблица в sql посыпалась), далее висят пхп потоки и кажется, что во всем виноват крайний - пхпфпм. Разумеется, перезапуск phpfpm лечит ситуацию, убивая зависшие коннекты. Но источник проблемы остается.
Спасибо, думал об этом. Смущает то, что подвисли все пулы причем ровно на одном сервере.
Вопрос в тему: приложение "подвисает" в одном из пулов, остальные (которые обслуживают другие приложения) должны работать адекватно?

ps. Зависший мемкеш я однажды встречал. При этом подвисали все детки на всех серверах, которым был нужен этот мемкеш.
 

tony2001

TeaM PHPClub
# sudo su -
# ps afx | grep php
# gdb attach <pid одного из чайлдов>
gdb> bt

тут либо станет понятно, либо покажи мне.
если сразу непонятно, то лучше посмотреть бэктрэйсы у нескольких разных процессов, чтоб наверняка.
 
  • Like
Реакции: Dovg

Dovg

Продвинутый новичок
Если повторится, обязательно соберу. Спасибо.
 

weregod

unserializer
у нас вёркеры зависают из-за eAccellerator, у которого косяк с блокировками
 

tony2001

TeaM PHPClub
>у нас вёркеры зависают из-за eAccellerator, у которого косяк с блокировками
та же фигня, но у нас зависает APC, а eAccelerator - нет.
но eAccelerator жрёт больше CPU.
 

tony2001

TeaM PHPClub
По поводу eAC и его (активного) потребления CPU:
Выяснил, что проблема в локах: очевидно, что 99.9999999% времени он только читает из кэша, а пишет туда только при рестарте/обновлении файлов. Из-за этого один процесс лочит кэш и все ждут этого лока, хотя могут спокойно читать параллельно, ведь ждать должен только пишущий процесс. Поэтому нужно разделение на чтение/запись у локов, а у дефолтовых спинлоков и семафоров такого нет.

Если использовать pthread rwlocks, то вопрос решается.
Оформлю патчик и пошлю этому Барту, которые eAC мэйнтенит теперь..
 

DiMA

php.spb.ru
Команда форума
Не понимаю привязанность к тому или иному кешу. Какая разница-то? Религиозные побуждения? Мы юзаем все их три. Вернее тот, который для текущей версии пхп выдает наиболее лучшую скорость. Заранее, планируя переход, выясняем как что работает (и совместим ли кеш вообще под новую версию пхп), проводим простое тестирование. Как минимум 2 из 3х всегда работают.
 

weregod

unserializer
кстати, у нас и APC, как eAcc, тоже в конце концов воркеры подвешивал, пока что остановились на XCache.
tony2001, спасибо за активность в направлении eAcc, но есть боязнь, что проект отчасти заморозился, последняя версия датируется 2010/05/31
 

tony2001

TeaM PHPClub
я пробовал xCache, результаты тут: http://xcache.lighttpd.net/ticket/240
я так понимаю, за 10 месяцев никаких движений. это грустно..

>есть боязнь, что проект отчасти заморозился, последняя версия датируется 2010/05/31
да, похоже на то.
но меня пока интересует его стабильность.
активность разработки APC пока не помогает решить проблемы с дедлоками.
 

Dovg

Продвинутый новичок
Код:
(gdb) bt
#0 0x00007f95a91130c7 in flock () from /lib/libc.so.6
#1 0x000000000056d7fb in ps_files_open (data=0x255c9c0, key=0x25602b8 "pd36abjgtjgcaemegco15aorg2") at /home/build/deb-src/php5-5.3.3/ext/session/mod_files.c:193
#2 0x000000000056da47 in ps_read_files (mod_data=0x6, key=0x2 <Address 0x2 out of bounds>, val=0x7fffef35cb10, vallen=0x7fffef35cb2c) at /home/build/deb-src/php5-5.3.3/ext/session/mod_files.c:351
#3 0x000000000056a675 in php_session_start () at /home/build/deb-src/php5-5.3.3/ext/session/session.c:533
#4 0x000000000056ad89 in zif_session_start (ht=6, return_value=0x25603e0, return_value_ptr=0x180, this_ptr=0xffffffffffffffff, return_value_used=1868641585)
 at /home/build/deb-src/php5-5.3.3/ext/session/session.c:1888
#5 0x00007f95a7e2f718 in xdebug_execute_internal (current_execute_data=0x7f959e4bf450, return_value_used=0) at /home/build/deb-src/xdebug-2.1.0/build-php5/xdebug.c:1339
#6 0x0000000000710498 in zend_do_fcall_common_helper_SPEC (execute_data=0x7f959e4bf450) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:318
#7 0x00000000006ebed1 in execute (op_array=0x2564c28) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:107
#8 0x00007f95a7e2f393 in xdebug_execute (op_array=0x2564c28) at /home/build/deb-src/xdebug-2.1.0/build-php5/xdebug.c:1272
#9 0x000000000071006a in zend_do_fcall_common_helper_SPEC (execute_data=0x7f959e4be720) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:340
#10 0x00000000006ebed1 in execute (op_array=0x2450ea0) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:107
#11 0x00007f95a7e2f393 in xdebug_execute (op_array=0x2450ea0) at /home/build/deb-src/xdebug-2.1.0/build-php5/xdebug.c:1272
#12 0x000000000071006a in zend_do_fcall_common_helper_SPEC (execute_data=0x7f959e4be450) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:340
#13 0x00000000006ebed1 in execute (op_array=0x2446090) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:107
#14 0x00007f95a7e2f393 in xdebug_execute (op_array=0x2446090) at /home/build/deb-src/xdebug-2.1.0/build-php5/xdebug.c:1272
#15 0x000000000071006a in zend_do_fcall_common_helper_SPEC (execute_data=0x7f959e4be068) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:340
#16 0x00000000006ebed1 in execute (op_array=0x23a3c18) at /home/build/deb-src/php5-5.3.3/Zend/zend_vm_execute.h:107
#17 0x00007f95a7e2f393 in xdebug_execute (op_array=0x23a3c18) at /home/build/deb-src/xdebug-2.1.0/build-php5/xdebug.c:1272
#18 0x00000000006bbf91 in zend_execute_scripts (type=0, retval=0x7fffef35d500, file_count=3) at /home/build/deb-src/php5-5.3.3/Zend/zend.c:1266
#19 0x0000000000664db8 in php_execute_script (primary_file=Cannot access memory at address 0x8000ef35c420
) at /home/build/deb-src/php5-5.3.3/main/main.c:2288
#20 0x000000000075208d in main (argc=0, argv=0x7fffef361c00) at /home/build/deb-src/php5-5.3.3/sapi/fpm/fpm/fpm_main.c:1865
Вот трейс.
Как я понял, проблема в блокировке файлов сессий.
К счастью, подвисло на тестовом сервере ,что позволило разобраться.

Вопрос: даже если виновато приложение (у нас уже стоит задача выкинуть сессии оттуда, где они не нужны :), почему flock не отвалился по таймауту, например?
max_execution_time 10, если что.
Оно зависло ночью, повесив всех деток и провисело до утра пока не сделали reload.
 

tony2001

TeaM PHPClub
гммм... я не совсем понимаю как ЭТО возможно.
flock() должен отпускаться автоматически системой, если процесс вышел/упал/куда-то делся.
мне кажется, что проблема где-то в другом месте, т.е. этот дедлок - это последствия другого дедлока.
PHP сами собирали или из дебиановских пакетов?
 

Dovg

Продвинутый новичок
tony2001:
Очень не хочется тащить в продакшен то, что собрано руками. Можно собрать для тестового, но сам факт того, что это не воспроизведется на тестовом не гаратирует отсутствия этой же ошибки на проде. А смена сборки - это уже риск ;)
А о dotdeb что можешь сказать? Там дают 5.3.5 с fpm.
 

tony2001

TeaM PHPClub
Там еще дают всякие левые патчи по пути.
Типа сухозина, timelib отдельно от ext/date для удобства мэйнтейнеров и др. г-но.
 
Сверху