php-fpm 0.5.9-rc1, new features

73 views
Skip to first unread message

Andrei Nigmatulin

unread,
May 25, 2008, 10:32:27 AM5/25/08
to highloa...@googlegroups.com
Привет всем !


Предлагаю принять участие в тестировании новых фич в php-fpm.

Для каждого пула воркеров теперь доступны новые директивы:

request_terminate_timeout - таймаут (в секундах) для исполнения php запроса,
после которого воркер будет принудительно перезапущен. Это то, что раньше
называлось request_execution_timeout и не работало.

request_slowlog_timeout - таймаут (в секундах) для исполнения php запроса,
после которого в отдельный лог сохранится php backtrace того места в скрипте,
на котором, возможно, подвис запрос.

slowlog - имя файла для этого лога.


Мне не очень нравятся названия этих директив, но пока ничего лучше не
придумал. Принимаются предложения.


Качать отсюда - http://php-fpm.anight.org/downloads/test/


--
Andrei Nigmatulin
GPG PUB KEY 6449830D

Now I lay me down to sleep(3)
Pray the OS my core to keep
If I die before I wake
Pray the Disk my core to take

Andrei Nigmatulin

unread,
May 25, 2008, 12:11:01 PM5/25/08
to highloa...@googlegroups.com
On Sunday 25 May 2008 18:32, Andrei Nigmatulin wrote:
> Для каждого пула воркеров теперь доступны новые директивы:
>
> request_terminate_timeout - таймаут (в секундах) для исполнения php
> запроса, после которого воркер будет принудительно перезапущен. Это то, что
> раньше называлось request_execution_timeout и не работало.
>
> request_slowlog_timeout - таймаут (в секундах) для исполнения php запроса,
> после которого в отдельный лог сохранится php backtrace того места в
> скрипте, на котором, возможно, подвис запрос.

Некоторые пояснения.

Эти два таймаута могут быть использованы вместе и по-отдельности. Не имеет
смысла только выставление request_slowlog_timeout >=
request_terminate_timeout.

После того как php backtrace сохранен в лог, запрос продолжает выполняться,
как будто ничего не случилось.

Как только сработал request_terminate_timeout - fastcgi соединение обрывается
и nginx выдает клиенту 502, которую можно перехватить и нарисовать красоту.

request_terminate_timeout задумывался как крайняя мера против подвисших
скриптов, если не сработал max_execution_time. Поэтому, есть смысл выставлять
его значение в max_execution_time + 1.

slowlog задумывался как инструмент в помощь администратору, чтобы можно было
предъявить обоснованные претензии программистам неторопливых скриптов.

silly_sad

unread,
May 26, 2008, 9:17:44 AM5/26/08
to highloa...@googlegroups.com
Andrei Nigmatulin wrote:
> Привет всем !
>
>
> Предлагаю принять участие в тестировании новых фич в php-fpm.
>
> Для каждого пула воркеров теперь доступны новые директивы:
>
> request_terminate_timeout - таймаут (в секундах) для исполнения php запроса,
> после которого воркер будет принудительно перезапущен. Это то, что раньше
> называлось request_execution_timeout и не работало.
>
> request_slowlog_timeout - таймаут (в секундах) для исполнения php запроса,
> после которого в отдельный лог сохранится php backtrace того места в скрипте,
> на котором, возможно, подвис запрос.
>
> slowlog - имя файла для этого лога.
>
>
> Мне не очень нравятся названия этих директив, но пока ничего лучше не
> придумал. Принимаются предложения.

нормальные названия
только
slowlog я бы заменил на slowlog_filename

Rauan Maemirov

unread,
May 27, 2008, 4:01:26 AM5/27/08
to highload-php-ru
Здравствуйте, Андрей!
А когда появится проставление параметров для одного пула, а потом их
применение как default-а для других?

On May 25, 10:11 pm, Andrei Nigmatulin <andrei.nigmatu...@gmail.com>
wrote:

Andrei Nigmatulin

unread,
May 27, 2008, 7:27:00 AM5/27/08
to highloa...@googlegroups.com
On Tuesday 27 May 2008 12:01, Rauan Maemirov wrote:
> Здравствуйте, Андрей!
> А когда появится проставление параметров для одного пула, а потом их
> применение как default-а для других?

После того, как будет готов новый test-based парсер конфига.

Andrei Nigmatulin

unread,
May 27, 2008, 8:57:13 AM5/27/08
to highloa...@googlegroups.com
On Monday 26 May 2008 17:17, silly_sad wrote:

> Andrei Nigmatulin wrote:
> > slowlog - имя файла для этого лога.
> >
> >
> > Мне не очень нравятся названия этих директив, но пока ничего лучше не
> > придумал. Принимаются предложения.
>
> нормальные названия
> только
> slowlog я бы заменил на slowlog_filename

Тогда по логике error_log надо тоже переименовать в error_log_filename ?

Alexandre Kalendarev

unread,
May 27, 2008, 2:45:20 PM5/27/08
to highloa...@googlegroups.com
> > Здравствуйте, Андрей!
> > А когда появится проставление параметров для одного пула, а потом их
> > применение как default-а для других?
>
> После того, как будет готов новый test-based парсер конфига.

Работы над парсером конфига я продолжу после 1-го июня. Через пару дней (на пхп Конф) я встречусь с Андреем и обсужу некоторые детали.


Александр

PS. Вообще-то моя фирма закрылась и я временно без работы, положение не стабильное, по этому возможны еще какие-то проволочки, пока не трудоустроюсь.

Antony Dovgal

unread,
May 27, 2008, 2:49:43 PM5/27/08
to highloa...@googlegroups.com
On 27.05.2008 22:45, Alexandre Kalendarev wrote:
>> > Здравствуйте, Андрей!
>> > А когда появится проставление параметров для одного пула, а потом их
>> > применение как default-а для других?
>>
>> После того, как будет готов новый test-based парсер конфига.
>
> Работы над парсером конфига я продолжу после 1-го июня. Через пару дней (на пхп Конф) я встречусь с Андреем и обсужу некоторые детали.

http://www.hyperrealm.com/libconfig/

Такой парсер не подойдёт?

--
Wbr,
Antony Dovgal

Andrei Nigmatulin

unread,
May 27, 2008, 3:01:50 PM5/27/08
to highloa...@googlegroups.com

Нет, он LGPL, а это не совместимо с лицензией php ;-)

Antony Dovgal

unread,
May 27, 2008, 3:01:22 PM5/27/08
to highloa...@googlegroups.com

И я забыл совсем: а в чем проблема с встроенным PHP-шным ini-парсером?
Чем он не подходит?

--
Wbr,
Antony Dovgal

Andrei Nigmatulin

unread,
May 27, 2008, 3:22:55 PM5/27/08
to highloa...@googlegroups.com

Antony Dovgal

unread,
May 27, 2008, 3:47:03 PM5/27/08
to highloa...@googlegroups.com
On 27.05.2008 23:22, Andrei Nigmatulin wrote:
>> И я забыл совсем: а в чем проблема с встроенным PHP-шным ini-парсером?
>> Чем он не подходит?
>
> http://groups.google.com/group/highload-php-en/msg/993c1c54083f618a

Вариант такой:

[pool_1]
setting1 = 0
setting2 = /path/to/dev/null

[pool2]
setting1 = 123
setting2 = /point/to/nowhere

Andrei Nigmatulin

unread,
May 27, 2008, 3:52:52 PM5/27/08
to highloa...@googlegroups.com
On Tuesday 27 May 2008 23:47, Antony Dovgal wrote:
> On 27.05.2008 23:22, Andrei Nigmatulin wrote:
> >> И я забыл совсем: а в чем проблема с встроенным PHP-шным ini-парсером?
> >> Чем он не подходит?
> >
> > http://groups.google.com/group/highload-php-en/msg/993c1c54083f618a
>
> Вариант такой:
>
> [pool_1]
> setting1 = 0
> setting2 = /path/to/dev/null
>
> [pool2]
> setting1 = 123
> setting2 = /point/to/nowhere

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

a.zhu...@gmail.com

unread,
May 27, 2008, 3:56:22 PM5/27/08
to Andrei Nigmatulin, highloa...@googlegroups.com
On Tue, May 27, 2008 at 11:22:55PM +0400, Andrei Nigmatulin wrote:
> On Tuesday 27 May 2008 23:01, Antony Dovgal wrote:
> > On 27.05.2008 22:49, Antony Dovgal wrote:
> > > On 27.05.2008 22:45, Alexandre Kalendarev wrote:
> > >>> > Здравствуйте, Андрей!
> > >>> > А когда появится проставление параметров для одного пула, а потом их
> > >>> > применение как default-а для других?
> > >>>
> > >>> После того, как будет готов новый test-based парсер конфига.
> > >>
> > >> Работы над парсером конфига я продолжу после 1-го июня. Через пару дней
> > >> (на пхп Конф) я встречусь с Андреем и обсужу некоторые детали.
> > >
> > > http://www.hyperrealm.com/libconfig/
> > >
> > > Такой парсер не подойдёт?
> >
> > И я забыл совсем: а в чем проблема с встроенным PHP-шным ini-парсером?
> > Чем он не подходит?
>
> http://groups.google.com/group/highload-php-en/msg/993c1c54083f618a

"If I would look for another format for php-fpm configuration file I
would rather choose some nice c-style syntax, like nginx.conf does
have."

Just an idea,
If you are looking of examples of software with BSD license which already provide
possibility to parse configuration files with C style format then you might take a look
at nginx source (src/core/ngx_conf_file.c) or ISC BIND (lib/isccfg/parser.c).

Best regards,
--
Alexander Zhuravlev

Alexandre Kalendarev

unread,
May 27, 2008, 4:33:17 PM5/27/08
to highloa...@googlegroups.com

Andrei Nigmatulin

unread,
May 27, 2008, 4:36:13 PM5/27/08
to highloa...@googlegroups.com

Yes, I had looked at the sources of nginx and found many useful ideas for
myself. However, I'm pretty sure that writing such a parser is not a rocket
science. So I decided not to take a code, but only ideas for realisation.

For now, we (me and Alexandre Kalendarev) considered use of re2c for this
purpose. It is simple and flexible parser generator that can produce
embeddable code for almost any kind of config syntax and structure.

silly_sad

unread,
May 28, 2008, 8:42:22 AM5/28/08
to highloa...@googlegroups.com
Andrei Nigmatulin wrote:
> On Monday 26 May 2008 17:17, silly_sad wrote:
>> Andrei Nigmatulin wrote:
>>> slowlog - имя файла для этого лога.
>>>
>>>
>>> Мне не очень нравятся названия этих директив, но пока ничего лучше не
>>> придумал. Принимаются предложения.
>> нормальные названия
>> только
>> slowlog я бы заменил на slowlog_filename
>
> Тогда по логике error_log надо тоже переименовать в error_log_filename ?

ну как хотите.
тока подчерки ставьте везде одинаково

silly_sad

unread,
May 28, 2008, 8:45:18 AM5/28/08
to highloa...@googlegroups.com
Andrei Nigmatulin wrote:
> On Tuesday 27 May 2008 12:01, Rauan Maemirov wrote:
>> Здравствуйте, Андрей!
>> А когда появится проставление параметров для одного пула, а потом их
>> применение как default-а для других?
>
> После того, как будет готов новый test-based парсер конфига.
>

слушайте
если вы ещё на такой стадии что не определились с парсером
может используете вот такой типа-SAX
http://sf.net/projects/urt

быстр, мал, тривиален, лицензия BSD

fixxxer

unread,
May 28, 2008, 3:15:45 PM5/28/08
to highload-php-ru
Лови багрепорт ;)

$ uname -a
FreeBSD srv01.ndev 7.0-STABLE FreeBSD 7.0-STABLE #2: Thu Feb 28
22:46:25 MSK 2008 ro...@srv01.ndev:/usr/obj/usr/src/sys/DEV amd64

<value name="request_terminate_timeout">10s</value>
<value name="request_slowlog_timeout">3s</value>

берем такой "скрипт"
<?

function i_am_idiot($i=0) {
echo $i."\n";
sleep(1);
i_am_idiot($i+1);
}

i_am_idiot();
?>

запрашиваем.

через 3 секунды, php-fpm.log

May 28 23:04:13.498172 [WARNING] fpm_request_check_timed_out(), line
135: child 50244, script '/home/fixxxer/www/web_request.php' (pool
ncp_fixxxer) executing too slow (3.104729 sec), logging
May 28 23:04:13.498264 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:04:13.498375 [NOTICE] fpm_children_bury(), line 188: child
50244 stopped for tracing
May 28 23:04:13.498387 [NOTICE] fpm_php_trace(), line 331: about to
trace 50244

28 секунд (похоже до max_execution_time) тупим. далее в slow log
падает:

May 28 23:03:41.430790 pid 50168 (pool ncp_fixxxer)
+++ dump failed

при попытке стопнуть php-fpm:

May 28 23:08:36.913221 [ERROR] fpm_trace_get_strz(), line 217:
ptrace(PEEKDATA) failed: Device busy (16)
May 28 23:08:36.913268 [ERROR] fpm_trace_detach(), line 90:
ptrace(DETACH) failed: Device busy (16)
May 28 23:08:36.913403 [NOTICE] fpm_php_trace(), line 359: finished
trace of 50244
May 28 23:08:36.913426 [NOTICE] fpm_got_signal(), line 56: received
SIGTERM
May 28 23:08:36.913461 [NOTICE] fpm_pctl(), line 253: switching to
'terminating' state
May 28 23:08:36.913494 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50243 (pool ncp_wwwrun)
May 28 23:08:36.913560 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50242 (pool ncp_wwwrun)
May 28 23:08:36.915771 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50241 (pool ncp_wwwrun)
May 28 23:08:36.915904 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50240 (pool ncp_wwwrun)
May 28 23:08:36.916709 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50247 (pool ncp_fixxxer)
May 28 23:08:36.917122 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50246 (pool ncp_fixxxer)
May 28 23:08:36.917435 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50245 (pool ncp_fixxxer)
May 28 23:08:36.917470 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50244 (pool ncp_fixxxer)
May 28 23:08:36.917542 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50251 (pool ncp_daos)
May 28 23:08:36.918446 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50250 (pool ncp_daos)
May 28 23:08:36.918490 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50249 (pool ncp_daos)
May 28 23:08:36.918618 [NOTICE] fpm_pctl_kill_all(), line 169: sending
signal 15 SIGTERM to child 50248 (pool ncp_daos)
May 28 23:08:36.918813 [NOTICE] fpm_pctl_kill_all(), line 178: 12
children are still alive
May 28 23:08:36.919186 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919212 [WARNING] fpm_children_bury(), line 213: child
50251 (pool ncp_daos) exited on signal 15 SIGTERM after 283.797103
seconds from start
May 28 23:08:36.919263 [WARNING] fpm_children_bury(), line 213: child
50250 (pool ncp_daos) exited on signal 15 SIGTERM after 283.798401
seconds from start
May 28 23:08:36.919303 [WARNING] fpm_children_bury(), line 213: child
50247 (pool ncp_fixxxer) exited on signal 15 SIGTERM after 283.801926
seconds from start
May 28 23:08:36.919354 [WARNING] fpm_children_bury(), line 213: child
50246 (pool ncp_fixxxer) exited on signal 15 SIGTERM after 283.803151
seconds from start
May 28 23:08:36.919389 [WARNING] fpm_children_bury(), line 213: child
50249 (pool ncp_daos) exited on signal 15 SIGTERM after 283.799634
seconds from start
May 28 23:08:36.919413 [WARNING] fpm_children_bury(), line 213: child
50245 (pool ncp_fixxxer) exited on signal 15 SIGTERM after 283.804234
seconds from start
May 28 23:08:36.919438 [NOTICE] fpm_children_bury(), line 188: child
50244 stopped for tracing
May 28 23:08:36.919465 [WARNING] fpm_children_bury(), line 213: child
50243 (pool ncp_wwwrun) exited on signal 15 SIGTERM after 283.806417
seconds from start
May 28 23:08:36.919514 [WARNING] fpm_children_bury(), line 213: child
50248 (pool ncp_daos) exited on signal 15 SIGTERM after 283.800926
seconds from start
May 28 23:08:36.919552 [WARNING] fpm_children_bury(), line 213: child
50242 (pool ncp_wwwrun) exited on signal 15 SIGTERM after 283.807689
seconds from start
May 28 23:08:36.919587 [WARNING] fpm_children_bury(), line 213: child
50241 (pool ncp_wwwrun) exited on signal 15 SIGTERM after 283.808508
seconds from start
May 28 23:08:36.919619 [WARNING] fpm_children_bury(), line 213: child
50240 (pool ncp_wwwrun) exited on signal 15 SIGTERM after 283.809279
seconds from start
May 28 23:08:36.919645 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919660 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919674 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919692 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919714 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919727 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919738 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919767 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919816 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919826 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919842 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 28 23:08:36.919872 [WARNING] fpm_request_check_timed_out(), line
147: child 50244, script '/home/fixxxer/www/web_request.php' (pool
ncp_fixxxer) execution timed out (266.526546 sec), terminating
May 28 23:08:37.042517 [WARNING] fpm_request_check_timed_out(), line
147: child 50244, script '/home/fixxxer/www/web_request.php' (pool
ncp_fixxxer) execution timed out (266.649191 sec), terminating
May 28 23:08:37.166012 [WARNING] fpm_request_check_timed_out(), line
147: child 50244, script '/home/fixxxer/www/web_request.php' (pool
ncp_fixxxer) execution timed out (266.772686 sec), terminating

и тут зацикливаемся, убивается только по -9.

Полный конфиг пула:

<section name="pool">
pool for user fixxxer
<value name="name">ncp_fixxxer</value>
<value name="listen_address">/var/tmp/phpfcgi-
fixxxer.sock</value>
<value name="listen_options">
<value name="backlog">-1</value>
<value name="owner">fixxxer</value>
<value name="group">developer</value>
<value name="mode">0666</value>
</value>
<value name="php_defines">
<value name="error_log">/var/log/php/fixxxer.log</
value>
</value>
<value name="user">fixxxer</value>
<value name="group">developer</value>
<value name="pm">
<value name="style">static</value>
<value name="max_children">4</value>
</value>
<value name="request_terminate_timeout">10s</value>
<value name="request_slowlog_timeout">3s</value>
<value name="slowlog">/var/log/php/slow-fixxxer.log</
value>
<value name="rlimit_files">1024</value>
<value name="rlimit_core">unlimited</value>
<value name="chroot"></value>
<value name="chdir"></value>
<value name="catch_workers_output">yes</value>
<value name="max_requests">500</value>
<value name="environment">
<value name="HOSTNAME">$HOSTNAME</value>
<value name="PATH">/usr/local/bin:/usr/bin:/bin</
value>
<value name="TMP">/tmp</value>
<value name="TMPDIR">/tmp</value>
<value name="TEMP">/tmp</value>
<value name="OSTYPE">$OSTYPE</value>
<value name="MACHTYPE">$MACHTYPE</value>
<value name="MALLOC_CHECK_">2</value>
</value>
</section>

Вот такие пироги.

Если нужна тестовая машинка с Freebsd 7, стучись в личку :)


On May 25, 8:11 pm, Andrei Nigmatulin <andrei.nigmatu...@gmail.com>
wrote:

fixxxer

unread,
May 28, 2008, 11:07:02 PM5/28/08
to highload-php-ru
Посмотрел исходники. Признаться, не понял, почему оно работает на 6.2
(а работает, факт :) - в STOP детка явно нигде не загоняется...

Тупо добавил в fpm_trace_attach() перед PTRACE_PEEKDATA

kill(pid, SIGSTOP);
waitpid(pid, NULL, WUNTRACED);

с такой модификацией, ругается теперь уже на Bad address в
fpm_trace_get_strz -> fpm_trace_get_long(addr), но, по крайней мере,
ничего не "подвешивается":

May 29 06:48:40.569413 [WARNING] fpm_request_check_timed_out(), line
135: child 97703, script '/home/fixxxer/www/web_request.php' (pool
ncp_fixxxer) executing too slow (3.112730 sec), logging
May 29 06:48:40.569522 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
May 29 06:48:40.569646 [NOTICE] fpm_children_bury(), line 188: child
97703 stopped for tracing
May 29 06:48:40.569661 [NOTICE] fpm_php_trace(), line 331: about to
trace 97703
May 29 06:48:40.569780 [ERROR] fpm_trace_get_strz(), line 225:
ptrace(PEEKDATA) failed: Bad address (14)
May 29 06:48:40.569888 [NOTICE] fpm_php_trace(), line 359: finished
trace of 97703


On May 28, 11:15 pm, fixxxer <fixxxe...@gmail.com> wrote:
> Лови багрепорт ;)
>
> $ uname -a
> FreeBSD srv01.ndev 7.0-STABLE FreeBSD 7.0-STABLE #2: Thu Feb 28
> 22:46:25 MSK 2008     r...@srv01.ndev:/usr/obj/usr/src/sys/DEV  amd64
>

silly_sad

unread,
May 29, 2008, 3:52:28 AM5/29/08
to highloa...@googlegroups.com
Andrei Nigmatulin wrote:
> Привет всем !
>
>
> Предлагаю принять участие в тестировании новых фич в php-fpm.
>

SunOS crisp.localnet.antora 5.10 Generic_118844-26 i86pc i386 i86pc

всё хорошо.
в логах красота.
nginx возвращает ошибка 502


настройки:
<value name="request_terminate_timeout">20s</value>


<value name="request_slowlog_timeout">3s</value>

<value name="slowlog">/var/log/php-slow.log</value>


скрипт:
<?

function i_am_idiot($i=0) {
echo $i."\n";
sleep(1);
i_am_idiot($i+1);
}

i_am_idiot();
?>


php-fpm.log:
May 29 11:44:19.531537 [WARNING] fpm_request_check_timed_out(), line
135: child 28942, script '/b/squirrel/tttit.php' (pool default)
executing too slow (3.044807 sec), logging
May 29 11:44:19.531777 [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
May 29 11:44:19.531810 [NOTICE] fpm_children_bury(), line 188: child
28942 stopped for tracing
May 29 11:44:19.531831 [NOTICE] fpm_php_trace(), line 331: about to
trace 28942
May 29 11:44:19.533824 [NOTICE] fpm_php_trace(), line 359: finished
trace of 28942
May 29 11:44:19.533927 [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
May 29 11:44:36.520998 [WARNING] fpm_request_check_timed_out(), line
147: child 28942, script '/b/squirrel/tttit.php' (pool default)
execution timed out (20.034778 sec), terminating
May 29 11:44:36.525719 [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
May 29 11:44:36.525802 [WARNING] fpm_children_bury(), line 213: child
28942 (pool default) exited on signal 15 SIGTERM after 144.895942
seconds from start
May 29 11:44:36.527672 [NOTICE] fpm_children_make(), line 350: child
29010 (pool default) started


php-slow.log:
May 29 11:44:19.532015 pid 28942 (pool default)
script_filename = /b/squirrel/tttit.php
[0x08044d60] sleep() /b/squirrel/tttit.php:5
[0x08044eb0] i_am_idiot() /b/squirrel/tttit.php:6
[0x08045000] i_am_idiot() /b/squirrel/tttit.php:6
[0x08045150] i_am_idiot() /b/squirrel/tttit.php:6
[0x08045260] i_am_idiot() /b/squirrel/tttit.php:9

Itreek

unread,
May 29, 2008, 1:50:55 PM5/29/08
to highload-php-ru
Еще один баг-репорт:

May 29 02:29:45.874605 [WARNING] fpm_request_check_timed_out(), line
135: child 95569, script '/home/web/SITE_NAME/www/download.php' (pool
default) executing too slow (7062.618271 sec), logging

May 29 08:10:43.550872 [NOTICE] fpm_children_bury(), line 188: child
95569 stopped for tracing
May 29 08:10:43.550908 [NOTICE] fpm_php_trace(), line 331: about to
trace 95569
May 29 09:16:09.652229 [ERROR] fpm_php_trace_dump(), line 275:
ptrace(PEEKDATA) failed: Bad address (14)
May 29 09:16:09.687967 [NOTICE] fpm_php_trace(), line 359: finished
trace of 95569

в slow.log:

May 29 09:16:09.652144 pid 95569 (pool default)
script_filename = /hom
[0xffffffffffffab20] +++ dump failed

Причем script_filename в slow.log именно "/hom"

при попытке: ./sbin/php-fpm stop

В логе:

May 29 21:27:54.985902 [ERROR] fpm_trace_get_strz(), line 217:
ptrace(PEEKDATA) failed: Device busy (16)
May 29 21:27:54.985932 [ERROR] fpm_trace_detach(), line 90:
ptrace(DETACH) failed: Device busy (16)
May 29 21:27:54.985970 [NOTICE] fpm_php_trace(), line 359: finished
trace of 95566
May 29 21:27:54.985987 [NOTICE] fpm_children_bury(), line 188: child
95565 stopped for tracing
May 29 21:27:54.985997 [NOTICE] fpm_php_trace(), line 331: about to
trace 95565
May 29 21:29:05.928776 [ERROR] fpm_trace_get_strz(), line 217:
ptrace(PEEKDATA) failed: Device busy (16)
May 29 21:29:05.928832 [ERROR] fpm_trace_detach(), line 90:
ptrace(DETACH) failed: Device busy (16)

Убивается только при killall -9 php-fpm

ОС FreeBSD 7.0-STABLE #1: Fri May 16 20:58:15 MSD 2008 amd64

Идентичных записей много, привел одну для примера.
При этом php-fpm полностью отказывается принимать коннекты.
Соответственно в nginx: - 502.

upstream timed out (60: Operation timed out)


On 25 май, 20:11, Andrei Nigmatulin <andrei.nigmatu...@gmail.com>
wrote:

fixxxer

unread,
Jun 1, 2008, 1:26:08 PM6/1/08
to highload-php-ru
Тэкс, я разобрался, как вся эта кухня работает. Имеем две проблемы.

Первая - sigstop надо слать после attach, иначе почему-то на FreeBSD
7.х выполнение процесса возобновляется. Впрочем, во всех встреченных
мной примерах использования ptrace sigstop+wait делается именно после
attach, так что похоже, что так и надо делать.

Вторая - ptrace(PEEKDATA) возвращает 32битный int, соответственно,
имеем жопу на 64битных платформах. Единственное, что пришло в голову,
- использовать PT_IO (заодно чутка оптимизируем получение строки).

Предлагаемый патч: http://symbi.org/misc/trace_pt_io.patch

Тестировал только на FreeBSD 6.2-i386 и 7.0-amd64, и не исключаю, что
что-либо сломал. ;)

Alexey V. Karagodov

unread,
Jul 11, 2008, 12:53:46 PM7/11/08
to highloa...@googlegroups.com
вроде работает
но иногда проскакивает:

16952 (pool default)
+++ dump failed

Alexey V. Karagodov

unread,
Jul 12, 2008, 4:20:28 PM7/12/08
to highloa...@googlegroups.com
после суток работы, pid-файл пропал, пхп перестал нормально выполнять
запросы
в логах куча сообщений типа

[WARNING] fpm_request_check_timed_out(), line 130: child XXXX, script
'/some/path/index.php5' (pool default) executing too slow (20.096824
sec), logging


[NOTICE] fpm_got_signal(), line 48: received SIGCHLD

[NOTICE] fpm_children_bury(), line 188: child XXXXX stopped for tracing
[NOTICE] fpm_php_trace(), line 390: about to trace XXXXX
[NOTICE] fpm_php_trace(), line 418: finished trace of XXXXX

XXXXX (pool default)
script_filename = /some/path/index.php

судя по ps axu | grep php-cgi пхп ничего не делает (памяти не ест,
проц ему не нужен)
перезапустил с помощью kill
начал нормально работать
какая ещё нужна информация?

fixxxer

unread,
Jul 13, 2008, 9:07:02 PM7/13/08
to highload-php-ru
К сожалению, я сейчас вряд ли смогу чем-либо помочь, времени
соврешенно нет, да и как воспроизвести ситуацию непонятно. Думаю, что
не стоит ковыряться в моем наколеночном патче - его целью было
обозначить проблему и возможное решение. Стоит подождать 0.5.9-rc2.

On Jul 13, 12:20 am, "Alexey V. Karagodov" <k...@karagodov.name>
wrote:

Alexey V. Karagodov

unread,
Jul 13, 2008, 9:09:40 PM7/13/08
to highloa...@googlegroups.com
вопроизвести тяжело
но очень нужен результат трейса медленных скриптов
лечится очень просто - перезагруз в 5 утра
ждём новых релизов, спасибо :)
Reply all
Reply to author
Forward
0 new messages