Как узнать, какой запрос в настоящий момент выполняет php-cgi процесс?

Labutin

Новичок
Как узнать, какой запрос в настоящий момент выполняет php-cgi процесс?

Сервер функционирует по следующей схеме. Запущено 20 php-cgi процессов:
su -c "export PHP_FCGI_CHILDREN=20; export PHP_FCGI_MAX_REQUESTS=2000; /opt/php/bin/php-cgi --fpm" - nginx

nginx исполняет php скрипты обращаясь к этим процессам:

location ~ \.php$ {
root /opt/parts_nd;
fastcgi_pass 127.0.0.1:8888;
fastcgi_index index.php;
fastcgi_param SCRIPT_FILENAME /opt/parts_nd$fastcgi_script_name;
fastcgi_read_timeout 300;
include fastcgi_params;
}
Все бы хорошо, но бывают случаи, когда ВСЕ 20 процессов чем-то надолго озадачиваются :( При этом процессор не нагружен. И тогда nginx не может найти свободный php-cgi процесс для выполнения запросов.
Всякие отладки самих скриптов и дебажные печати не смогли выявить проблемные запросы к сайту, которые иногда приводят к слишком долгой обработке запросов.

Итак сам вопрос :) Имеем 20 php-cgi процессов в памяти. Как понять, какие именно php скрипты они обрабатывают в текущий момент? Т.е. как только возникнет очередное подвисание, я хочу проанализировать, чем заняты процессы.
Наверное можно приаттачиться к процессу с помощью gdb. Но что дальше? Я в gdb в общем-то 0 :(
Есть другие предложения?
 

Krishna

Продался Java
Тут вот в соседнем топике Pinba рекламируют. Но я сам не пробовал :)
 

Макс

Старожил PHPClub
еще есть http://pecl.php.net/package/proctitle - но я тоже не пробовал
на линуксе иногда можно понять чем занимается процесс через
strace -p <ид_процесса>
 

dimagolov

Новичок
как вариант пусть в shared memory процессы сохраняют свой pid и запрос, а ты будешь там смотреть
 

Dovg

Продвинутый новичок
strace ?

там по вызову может быть понятно, если они действительно чего-то ждут.
 

Alexandre

PHPПенсионер
Тут вот в соседнем топике Pinba рекламируют.
во FreeBSD не работает.
Как понять, какие именно php скрипты они обрабатывают в текущий момент? Т.е. как только возникнет очередное подвисание, я хочу проанализировать, чем заняты процессы.
смотрю в топе какой скрипт занял наибольшее число процессора (подвис), смотрю его пид, по пиду смотрю - открытые файлы. Иногда помогает.
так же можно посмотреть по ps ax| grep <pid> если все не завернуто на index.php
 

Labutin

Новичок
strace очень помогло - скрипты вставали на flock'е :(
Кусок кода с flock в данном случае морально устарел и был удален.
Очень надеюсь, что проблема теперь будет решена.
Всем большое спасибо за советы!!!

-~{}~ 10.10.09 11:00:

Приключения продолжаются :(
В своем кода на PHP избавился от вызова
flock($fp, LOCK_EX);
но через некоторое время все процессы снова встали :(
Поключился к процессу с помощью strace:
[root@php-dell ~]# strace -p 14739
Process 14739 attached - interrupt to quit
flock(4, LOCK_EX)

Тут я чего-то недопонимаю :( Неужели внутри самого PHP проблемы?

P.S. PHP Version 4.4.9
'./configure' '--with-mysql' '--prefix=/opt/php' '--with-mssql' '--with-iconv' '--enable-fastcgi' '--enable-fpm' '--with-curl=/opt/curl/' '--with-gd' '--with-zlib' '--with-ttf' '--enable-gd-native-ttf' '--with-freetype-dir=/usr/lib' '--with-freetype-dir' '--with-ttf-dir=/usr/include/freetype2' '--with-zlib-dir=/usr/lib' '--with-png-dir=/usr/lib' '--with-jpeg-dir=/usr/lib' '--with-freetype' '--with-imap' '--with-kerberos' '--with-imap-ssl' '--enable-ftp' '--enable-memory-limit'
 

Макс

Старожил PHPClub
lsof -p 14739
он показывает список файлов, открытых процессом.
Попробуй понять на каком файле блокировка висит
 

Labutin

Новичок
В момент подвисания сайта выдержка из lsof

php-cgi 15644 nginx 4u REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89
php-cgi 15647 nginx 4u REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89
php-cgi 15648 nginx 4uW REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89
php-cgi 16132 nginx 4u REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89
php-cgi 16145 nginx 4u REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89
php-cgi 17512 nginx 4u REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89
php-cgi 17688 nginx 4u REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89
php-cgi 17698 nginx 4u REG 253,0 216189 24712133 /opt/php/tmp/sess_1f130ab86c185d0fd38413d105e00a89

Я тут погуглил - несколько лет назад в PHP вроде как был баг - блокировался на сессиях при работе в режиме fastcgi. У меня именно так и запущен PHP (см. первый пост). Неужели баг в силе?
На всякий случай - /opt/php/tmp/ - это НЕ сетевая папка
CentOS release 5.3 (Final)

-~{}~ 10.10.09 14:30:

http://bugs.php.net/bug.php?id=14628 вот про баг
Кстати, а как сделать так, чтобы strace вывел не последннюю команду, а несколько предыдущих (стек вызовов) ?
 

Макс

Старожил PHPClub
насколько я понял твою проблему, это не баг - так работают пхп-сессии, когда хранятся в файлах (независимо от того fcgi это или mod_php).
скорее всего тебе надо читать про http://php.net/session_write_close и в нужных местах вставить его

-~{}~ 10.10.09 14:35:

Кстати, а как сделать так, чтобы strace вывел не последннюю команду, а несколько предыдущих (стек вызовов) ?
strace показывает системные вызовы, которые происходят в данный момент в процессе, он не может узнать какие системные вызовы были в прошлом
 

Labutin

Новичок
Расследование продолжается :)
Да, процессы блокируются на доступе к файлам сессий. Виновник - первый скрипт, который заблокировал - остальные просто ждут на flock'е. Т.е. нужно выяснить - чего там первый скрипт застрял. В приведенном выше примере - это 15648
Сегодня снова все зависло. Вот strace виновного процесса:
[root@php-dell ~]# strace -p 25578
Process 25578 attached - interrupt to quit
select(7, [6], NULL, NULL, {3, 61000}) = 0 (Timeout)
time(NULL) = 1255362238
time(NULL) = 1255362238
select(7, [6], NULL, NULL, {10, 0}) = 0 (Timeout)
time(NULL) = 1255362248
time(NULL) = 1255362248
select(7, [6], NULL, NULL, {10, 0}) = 0 (Timeout)
time(NULL) = 1255362258
time(NULL) = 1255362258
select(7, [6], NULL, NULL, {10, 0}) = 0 (Timeout)
time(NULL) = 1255362268
time(NULL) = 1255362268
select(7, [6], NULL, NULL, {10, 0}) = 0 (Timeout)
time(NULL) = 1255362278
time(NULL) = 1255362278
select(7, [6], NULL, NULL, {10, 0}) = 0 (Timeout)
time(NULL) = 1255362288
time(NULL) = 1255362288

Есть предположения - чего в нем такое происходит?
 

dimagolov

Новичок
Labutin, ищи в нем бесконечный цикл. отлаживай его, в конце концов.
 

Макс

Старожил PHPClub
Смотри какие у тебя у тебя сетевые взаимодействия в этом скрипте ?
С чем он по сети работает ? mysql, memcached, какая-то другая бд, или HTTP-запросы на другие сервера шлешь ?
ну и пройдись по коду, поищи вызовы socket_select()

lsof -p 25578 вроде и сетевые соединения показывает - тоже может быть полезно

-~{}~ 12.10.09 23:39:

ну работа с mysql и memcached к такому конечно не приводит - просто отсмотри все работу с чем-то удаленным по сети
 

Labutin

Новичок
dimagolov
В том то и дело, что обычно все работает нормально.

Макс
socket_select - нет в коде вообще.
Подозрение пало на mssql_query
Дело вот в чем. Есть обращение к базе 1С на MSSQL. 1C-ка иногда блокирует таблицы и не факт, что запрос завершится удачно. В php.ini стоит:
mssql.connect_timeout=5
mssql.timeout=10
Обратите внимание на пример выше - там как раз select через каждые 10 секунд вызывается.
Т.е. есть версия, что mssql_query вместо того, чтобы через 10 секунд отвалиться просто там зацикливается :(
Такое возможно?
 

dimagolov

Новичок
пиши в лог перед и после обращения к mssql. кроме того, ты можешь отфильтровать tcp запросы к mssql и смотреть что происходит, причем tcpdump можно пускать уже по факту повисшего процесса.
 

Labutin

Новичок
Макс
Спасибо, это мой случай :(
http://www.phpclub.ru/talk/showthread.php?s=&threadid=116579
Может быть есть мысли?
 
Сверху