how to debug crashing php-cgi instances

[mar...@hyves.nl]

Hi list,

I've configured php-fpm to work with nginx, php-5.2.8,
eaccelerator-0.9.5.3 and pecl-memcache2.1.0. Although it works fine
some times a php-cgi process crashes.

php-cgi[15521]: segfault at 00000001895aa810 rip 0000000000574e97 rsp
00007fffa2089420 error 6

No crashes occur when I use the same setup with apache2 and mod_php
and the same modules. I'm also seeing a couple of warnings like

[WARNING] fpm_stdio_child_said(), line 167: child 18668 (pool nginx)
said into stderr: "zend_mm_heap corrupted", this seems eaccelerator
related when I search for it on google.

My question is how can I debug this and do any of you experience
similar crashes?

I also tried to trace some of the instances which gave me the
following error in the logs:

[NOTICE] fpm_got_signal(), line 48: received SIGCHLD
[NOTICE] fpm_children_bury(), line 194: child 24843 stopped for
tracing
[NOTICE] fpm_php_trace(), line 139: about to trace 24843
[ERROR] fpm_trace_get_long(), line 78: ptrace(PEEKDATA) failed: Input/
output error (5)

Any idea how to get the ptrace working? I've set coredumps sizes to
unlimited via ulimit and via <value name="rlimit_core">unlimited</
value> in the config file.

If somebody has some pointers how to debug this, help is very much
appreciated.

Regards
Marlon

[Andrei Nigmatulin]

On Wednesday 17 December 2008 21:34, mar...@hyves.nl wrote:
> Hi list,
>
> I've configured php-fpm to work with nginx, php-5.2.8,
> eaccelerator-0.9.5.3 and pecl-memcache2.1.0. Although it works fine
> some times a php-cgi process crashes.
>
> php-cgi[15521]: segfault at 00000001895aa810 rip 0000000000574e97 rsp
> 00007fffa2089420 error 6
>
> No crashes occur when I use the same setup with apache2 and mod_php
> and the same modules. I'm also seeing a couple of warnings like
>
> [WARNING] fpm_stdio_child_said(), line 167: child 18668 (pool nginx)
> said into stderr: "zend_mm_heap corrupted", this seems eaccelerator
> related when I search for it on google.
>
> My question is how can I debug this and do any of you experience
> similar crashes?

You need to get a core and a backtrace of this crash.

If you're on linux try following:

# echo '/tmp/core-%e.%p' > /proc/sys/kernel/core_pattern
# echo 0 > /proc/sys/kernel/core_uses_pid

After that, if rlimit_core is set to 'unlimited' you will get a core file
in /tmp on the next crash.

> I also tried to trace some of the instances which gave me the
> following error in the logs:
>
> [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
> [NOTICE] fpm_children_bury(), line 194: child 24843 stopped for
> tracing
> [NOTICE] fpm_php_trace(), line 139: about to trace 24843
> [ERROR] fpm_trace_get_long(), line 78: ptrace(PEEKDATA) failed: Input/
> output error (5)
> Any idea how to get the ptrace working?

This is normal error, it is working.

The trace function in php-fpm is only for getting backtraces of worker
processes if they executing request too slow. The ptrace interface is
asynchronous by design and can not be used as reliable mean for getting php
backtrace.

It was designed to be useful in situations when php process hangs waiting for
network i/o, for example in mysql_query(). In this case a reliable php
backtrace is possible and it is likely to show you where php hangs (and
probably why).

> I've set coredumps sizes to
> unlimited via ulimit and via <value name="rlimit_core">unlimited</
> value> in the config file.
>
> If somebody has some pointers how to debug this, help is very much
> appreciated.
>
> Regards
> Marlon

--
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

[mar...@hyves.nl]

Hi Andrei,

> If you're on linux try following:
>
> # echo '/tmp/core-%e.%p' > /proc/sys/kernel/core_pattern
> # echo 0 > /proc/sys/kernel/core_uses_pid
>

Thanks for your info. I've got a coredump now. After running it
through gdb I got the following

#0 _zend_mm_free_int (heap=0x91d300, p=0x190c778) at /var/tmp/portage/
dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_alloc.c:832
832 if (UNEXPECTED(prev->next_free_block != mm_block) || UNEXPECTED
(next->prev_free_block != mm_block)) {
(gdb) bt
#0 _zend_mm_free_int (heap=0x91d300, p=0x190c778) at /var/tmp/portage/
dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_alloc.c:832
#1 0x000000000058c48e in zend_hash_destroy (ht=0x21a89a0) at /var/tmp/
portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_hash.c:531
#2 0x000000000059bd09 in zend_object_std_dtor (object=0x244f248) at /
var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_objects.c:
45
#3 0x000000000059bd29 in zend_objects_free_object_storage
(object=0x70) at /var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/
Zend/zend_objects.c:122
#4 0x000000000059f36e in zend_objects_store_del_ref_by_handle
(handle=1025)
at /var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/
zend_objects_API.c:206
#5 0x000000000059f39e in zend_objects_store_del_ref
(zobject=0x244f220)
at /var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/
zend_objects_API.c:168
#6 0x0000000000574ed6 in _zval_ptr_dtor (zval_ptr=0x24a8688) at /var/
tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_variables.h:35
#7 0x000000000058c468 in zend_hash_destroy (ht=0x21a8cb8) at /var/tmp/
portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_hash.c:526
#8 0x000000000058148f in _zval_dtor_func (zvalue=0x244b810) at /var/
tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_variables.c:43
#9 0x0000000000574ed6 in _zval_ptr_dtor (zval_ptr=0x244b3e0) at /var/
tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_variables.h:35
#10 0x000000000058c468 in zend_hash_destroy (ht=0x21a8d10) at /var/tmp/
portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_hash.c:526
#11 0x000000000059bd09 in zend_object_std_dtor (object=0x244b5f8) at /
var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/zend_objects.c:
45
#12 0x000000000059bd29 in zend_objects_free_object_storage
(object=0x70) at /var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/
Zend/zend_objects.c:122
#13 0x000000000059ef11 in zend_objects_store_free_object_storage
(objects=0x91bd20)
at /var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/Zend/
zend_objects_API.c:89
#14 0x000000000057545c in shutdown_executor () at /var/tmp/portage/dev-
lang/php-5.2.8/work/php-5.2.8/Zend/zend_execute_API.c:299
#15 0x0000000000581ab2 in zend_deactivate () at /var/tmp/portage/dev-
lang/php-5.2.8/work/php-5.2.8/Zend/zend.c:860
#16 0x000000000054063e in php_request_shutdown (dummy=<value optimized
out>) at /var/tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/main/
main.c:1492
#17 0x0000000000605cde in main (argc=2, argv=0x7fff8a85a528) at /var/
tmp/portage/dev-lang/php-5.2.8/work/php-5.2.8/sapi/cgi/cgi_main.c:2187

Still looking into it, perhaps you have a clue what's causing the
crash?

Regards
Marlon

[mar...@hyves.nl]

> If you're on linux try following:
>
> # echo '/tmp/core-%e.%p' > /proc/sys/kernel/core_pattern
> # echo 0 > /proc/sys/kernel/core_uses_pid
>
> After that, if rlimit_core is set to 'unlimited' you will get a core file
> in /tmp on the next crash.
>

Thanks for the info! I replayed a crash with gdb, still looking into
it but this is what happend