Segfaults with PHP 7.0.8

[tgagor]

I have CentOS 7 based environment with PHP-FPM from IUS repo. I compiled manually memcached module and it was working but not so well - from time too time it cause segfaults:

[19-Jul-2016 15:16:39] WARNING: [pool web] child 19880 exited on signal 11 (SIGSEGV - core dumped) after 99.885775 seconds from start
[19-Jul-2016 15:16:39] NOTICE: [pool web] child 20059 started

Trying to debug it I've got:

root /var/spool/abrt/ccpp-2016-07-19-14:37:04-14420 # gdb /usr/sbin/php-fpm coredump 
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-80.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/sbin/php-fpm...Reading symbols from /usr/lib/debug/usr/sbin/php-fpm.debug...done.
done.
[New LWP 14420]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `php-fpm: pool web              '.
Program terminated with signal 11, Segmentation fault.
#0  0x00007f95b6745577 in vfprintf () from /lib64/libc.so.6
(gdb) bt
#0  0x00007f95b6745577 in vfprintf () from /lib64/libc.so.6
#1  0x00007f95b6809e25 in __vsnprintf_chk () from /lib64/libc.so.6
#2  0x00007f95b6809d88 in __snprintf_chk () from /lib64/libc.so.6
#3  0x00007f95a84a8ce7 in memcached_set_error(org::libmemcached::Instance&, memcached_return_t, char const*) ()
   from /lib64/libmemcached.so.11
#4  0x00007f95a84a6ab5 in _memcached_connect(org::libmemcached::Instance*, bool) [clone .constprop.8] ()
   from /lib64/libmemcached.so.11
#5  0x00007f95a84aa7a0 in memcached_mget_by_key_real(memcached_st*, char const*, unsigned long, char const* const*, unsigned long const*, unsigned long, bool) () from /lib64/libmemcached.so.11
#6  0x00007f95a84ab480 in memcached_mget_by_key () from /lib64/libmemcached.so.11
#7  0x00007f95a86d599c in php_memc_mget_apply (intern=intern@entry=0x7f95b4603240, server_key=<optimized out>, 
    keys=keys@entry=0x7ffeaee6d1f0, result_apply_fn=result_apply_fn@entry=0x7f95a86d0df0 <s_get_multi_apply_fn>, 
    with_cas=<optimized out>, context=context@entry=0x7ffeaee6d1e0) at /tmp/memcache/php_memcached.c:672
#8  0x00007f95a86d5b1c in php_memc_mget_apply (context=0x7ffeaee6d1e0, with_cas=<optimized out>, 
    result_apply_fn=0x7f95a86d0df0 <s_get_multi_apply_fn>, keys=0x7ffeaee6d1f0, server_key=<optimized out>, 
    intern=0x7f95b4603240) at /tmp/memcache/php_memcached.c:1498
#9  php_memc_getMulti_impl (execute_data=<optimized out>, return_value=0x7f9589357b00, by_key=<optimized out>)
    at /tmp/memcache/php_memcached.c:1509
#10 0x00007f95b962dbdb in dtrace_execute_internal (execute_data=<optimized out>, return_value=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:107
#11 0x00007f95b96ba934 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:844
#12 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#13 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:83
#14 0x00007f95b96ba600 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:800
#15 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#16 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:83
#17 0x00007f95b96ba600 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:800
#18 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#19 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:83
#20 0x00007f95b96ba600 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:800
#21 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#22 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:83
#23 0x00007f95b96ba600 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:800
#24 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#25 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:83
#26 0x00007f95b96ba600 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:800
#27 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#28 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:83
#29 0x00007f95b96ba600 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:800
#30 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#31 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
    at /usr/src/debug/php-7.0.8/Zend/zend_dtrace.c:83
#32 0x00007f95b96ba600 in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:800
#33 0x00007f95b967c38b in execute_ex (ex=<optimized out>) at /usr/src/debug/php-7.0.8/Zend/zend_vm_execute.h:414
#34 0x00007f95b962dab9 in dtrace_execute_ex (execute_data=<optimized out>)
---Type <return> to continue, or q <return> to quit---q
 at /usr/src/debug/php-7.0.8/Zend/zend_dtraceQuit
(gdb) q

I don't know what to do next with that so any help is appreciated :-)

[laruence]

any reproduce script?

[tgagor]

It was during running Drupal with memcached module and PHP sessions in memcached. In such configuration one on five requests caused segfault and 503 error.
I tried to sniff memcached traffic to see what happen but Drupal generates from 200 to even 6000 req/s to memcached for single page request. It won't be easy to check all of this.
Will you be able to run prepare Drupal environment for test or should I prepare something in Docker or Vagrant?

[laruence]

could you please try again with the latest snapshot in php7 branch? I fixed something recently, not sure whether it is related

[tgagor]

I'm on vacation now but will try find time for this, I will let you know about results.

[tgagor]

I tested current code from php7 branch and it crushed on every request.

[laruence]

hmm, are you able to run php-fpm with valgrind? it may give us more infos, or you could grant me a ssh access to a reproduce able box? (my email is gmail)

[laruence]

I've installed drupal 8 and memcached module for drupal too, but I can not see the segfault while doing benchmark.

[tgagor]

I will be able to run valgrind and whatever debug tools you need but now for 2 weeks I'm on vacation with limited access to internet.
It's not possible to grant you access to that box, but I tested this on 3 vps machines on different servers so it's repeatable and not caused by ex. RAM degradation, etc.
Tell me what data you need and I will try to provide it to you.

[tgagor]

Here you have valgrind dump during failure:
https://transfer.sh/v0bc5/valgrind-dump.txt.gz

[laruence]

== Stack overflow in thread 1: can't grow stack to 0xffe801d48

hmm, seems stackoverflow?

hmm, could you show me how to reproduce it from a fresh start?

thanks very much for the help!

[tgagor]

I asked programmer working with me on this project where we have problem to help separate code causing problems - I will inform you about progress.

[laruence]

@tgagor any progress? :) thanks

[tgagor]

@laurence I'm back after vacation starting from today, I will push this further. I will try to prepare Vagrant environment so you could play with it.

[tgagor]

Hi again,

I prepared test environment with clean version of Drupal (exact we use on production), same version of memcache module for Drupal and tried to get similar results. Sadly I wasn't be able to reproduce this stack overflow in this test env ;-(

On production we have a lot more Drupal modules and a lot more article types with different snippets, etc. It's almost impossible to reproduce this in clean Drupal without a huge effort.

I tried to debug things with gdb to get values of variables provided to this function call so I could prepare simple example, but I don't know this tool well and was unable to extract this data.

Could we meet on IRC/Slack (or similar) so you could instruct me what more could I do to show where the problem is?
I'm not authorized to give you access to our site or site data :(

[laruence]

hmm.....it's sad that we can not reproduce it easily, anyway, I am not available on IRC till weekend.
maybe you could find me on #php.pecl on sunday? I am in UTC+8

[tgagor]

I tried to debug it further (to extract what parameters cause segfault) but without success. We abandoned memcached in this project and switched to redis.
Because of that switch I won't be able to provide more information - sorry for that.

[arielkung]

Hi,

We have segfaults with php 7.0.12 and latest memcached php7 branch.

It's happening in some cases when a multiget returns values with special chars. In second call to multiget for other values in same request we have segfaults:

exited on signal 11 (SIGSEGV - core dumped)

The coredump shows:

#0 0x000000314e889710 in memcpy () from /lib64/libc.so.6
#1 0x00007fd081fbc5da in ?? () from /usr/lib64/libmemcached.so.11
#2 0x00007fd081fbc741 in ?? () from /usr/lib64/libmemcached.so.11
#3 0x00007fd081fb989c in ?? () from /usr/lib64/libmemcached.so.11
#4 0x00007fd081fba200 in memcached_mget_by_key () from /usr/lib64/libmemcached.so.11
#5 0x00007fd0821e5f53 in ?? () from /usr/lib64/php/modules/memcached.so
#6 0x00007fd0821e63f6 in ?? () from /usr/lib64/php/modules/memcached.so
#7 0x00000000005d1349 in dtrace_execute_internal ()
#8 0x0000000000657c32 in ?? ()
#9 0x000000000061f830 in execute_ex ()
#10 0x00000000005d148e in dtrace_execute_ex ()
#11 0x0000000000657aaa in ?? ()

[sodabrew]

@arielkung Could you recompile your libmemcached with debugging symbols, or if you're using system packages, install the debug package such as https://packages.debian.org/jessie/libmemcached-dbg ? That will fill-in the ??? lines in the backtrace and make it possible to see where the problem is more specifically.

I'm unscheduling this from a fix target for now.

[carlwgeorge]

@tgagor You mentioned IUS in your original post. You don't have to manually compile the memcached module anymore. We have php70u-pecl-memcached available in our testing repository, as well as the corresponding php70u-pecl-memcached-debuginfo to get the debugging symbols @sodabrew was referring to.

[tgagor]

I asked for help half a year ago. It was looking at that time, that solution won't arrive soon, so we decided to switch to Redis. It was working without problems and added some value with ex. no more empty cache after service restart.

Thanks to this issue I learned Redis and now I prefer it over memcached.

Right now I don't have access to this environment and can't help with that. It's not resolved but I don't see sense to keep this issue open.

[tgagor]

Thanks for your engagement.

[sodabrew]

@arielkung If your crash continues to occur, please open a new ticket with the suggested packages for a more complete backtrace. It's likely that you had a separate issue from the OP.