Many segment faults in multi-exec #960

yushengery · 2016-09-23T09:42:14Z

Greetings ,
I am using multi(pipeline) a lot , however I found a lot of coredump in the PHP-fpm redis.so
OS: Amazon Linux AMI release 2016.03 64Bit
PHP: 7.0.9
phpredis git commit : a224ed3

coredump info:

[root@ip-172-31-0-147 ~]# gdb /usr/local/php-7.0.9/sbin/php-fpm /data/coredump/core.php-fpm.11.1474621822.20576
GNU gdb (GDB) Amazon Linux (7.6.1-64.33.amzn1)
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-amazon-linux-gnu".
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /usr/local/php-7.0.9/sbin/php-fpm...done.
[New LWP 20576]
Missing separate debuginfo for /usr/lib64/libpq.so.5
Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/bc/283b2d932e2d4651c4235ba91dd47e921b7d58.debug
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Missing separate debuginfo for /usr/lib64/libstdc++.so.6
Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/0a/90c35d3174805453ea67a785446d628e298b59.debug
Missing separate debuginfo for /lib64/libgcc_s.so.1
Try: yum --enablerepo='debug' install /usr/lib/debug/.build-id/00/fa2883fb47b1327397bbf167c52f51a723d013.debug
Core was generated by `php-fpm: pool php7 '.
Program terminated with signal 11, Segmentation fault.
#0 0x00007f9985061949 in redis_mbulk_reply_assoc (execute_data=0x7f998ba136e0, return_value=0x7f998ba136b0, redis_sock=0x7f998ba5e240, z_tab=0x7ffd2a57b3c0, ctx=0x7f998ba6b380)

at /usr/local/soft/php-7.0.9/ext/phpredis/library.c:1924

1924 add_assoc_stringl_ex(&z_multi_result, Z_STRVAL(z_keys[i]), Z_STRLEN(z_keys[i]), response, response_len);
Missing separate debuginfos, use: debuginfo-install cyrus-sasl-lib-2.1.23-13.16.amzn1.x86_64 glibc-2.17-106.167.amzn1.x86_64 keyutils-libs-1.5.8-3.12.amzn1.x86_64 krb5-libs-1.13.2-12.40.amzn1.x86_64 libcom_err-1.42.12-4.40.amzn1.x86_64 libcurl-7.40.0-8.58.amzn1.x86_64 libidn-1.18-2.8.amzn1.x86_64 libmcrypt-2.5.8-9.1.2.amzn1.x86_64 libselinux-2.1.10-3.22.amzn1.x86_64 libssh2-1.4.2-2.13.amzn1.x86_64 libxml2-2.9.1-6.3.49.amzn1.x86_64 nspr-4.11.0-1.37.amzn1.x86_64 nss-3.21.0-9.76.amzn1.x86_64 nss-softokn-freebl-3.16.2.3-14.2.38.amzn1.x86_64 nss-util-3.21.0-2.2.50.amzn1.x86_64 openldap-2.4.40-7.28.amzn1.x86_64 openssl-1.0.1k-14.91.amzn1.x86_64 xz-libs-5.1.2-12alpha.12.amzn1.x86_64 zlib-1.2.8-7.18.amzn1.x86_64
(gdb) bt
#0 0x00007f9985061949 in redis_mbulk_reply_assoc (execute_data=0x7f998ba136e0, return_value=0x7f998ba136b0, redis_sock=0x7f998ba5e240, z_tab=0x7ffd2a57b3c0, ctx=0x7f998ba6b380)

at /usr/local/soft/php-7.0.9/ext/phpredis/library.c:1924

#1 0x00007f998503d450 in fold_this_item (execute_data=0x7f998ba136e0, return_value=0x7f998ba136b0, item=0x31130f0, redis_sock=0x7f998ba5e240, z_tab=0x7ffd2a57b3c0)

at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2470

#2 0x00007f998503d4af in redis_sock_read_multibulk_multi_reply_loop (execute_data=0x7f998ba136e0, return_value=0x7f998ba136b0, redis_sock=0x7f998ba5e240, z_tab=0x7ffd2a57b3c0,

numElems=0) at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2483

#3 0x00007f998503ccdd in redis_sock_read_multibulk_pipeline_reply (execute_data=0x7f998ba136e0, return_value=0x7f998ba136b0, redis_sock=0x7f998ba5e240)

at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2288

#4 0x00007f998503d319 in zim_Redis_exec (execute_data=0x7f998ba136e0, return_value=0x7f998ba136b0) at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2439
#5 0x0000000000857dab in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/local/soft/php-7.0.9/Zend/zend_vm_execute.h:842
#6 0x000000000081a2eb in execute_ex (ex=) at /usr/local/soft/php-7.0.9/Zend/zend_vm_execute.h:414
#7 0x00000000008635f7 in zend_execute (op_array=0x7f998ba6b000, op_array@entry=0x7f9980d8a8d8, return_value=return_value@entry=0x7f998ba135b0)

at /usr/local/soft/php-7.0.9/Zend/zend_vm_execute.h:458

#8 0x00000000007ddf34 in zend_execute_scripts (type=type@entry=8, retval=0x7f998ba135b0, retval@entry=0x0, file_count=file_count@entry=3)

at /usr/local/soft/php-7.0.9/Zend/zend.c:1427

#9 0x0000000000782850 in php_execute_script (primary_file=primary_file@entry=0x7ffd2a57d910) at /usr/local/soft/php-7.0.9/main/main.c:2494
#10 0x000000000044055c in main (argc=, argv=) at /usr/local/soft/php-7.0.9/sapi/fpm/fpm/fpm_main.c:1968

(gdb) l
1919 if(response != NULL) {
1920 zval z;
1921 if(redis_unserialize(redis_sock, response, response_len, &z) == 1) {
1922 add_assoc_zval_ex(&z_multi_result, Z_STRVAL(z_keys[i]), Z_STRLEN(z_keys[i]), &z);
1923 } else {
1924 add_assoc_stringl_ex(&z_multi_result, Z_STRVAL(z_keys[i]), Z_STRLEN(z_keys[i]), response, response_len);
1925 }
1926 efree(response);
1927 } else {
1928 add_assoc_bool_ex(&z_multi_result, Z_STRVAL(z_keys[i]), Z_STRLEN(z_keys[i]), 0);
(gdb) p numElems
$8 = 38
(gdb) p i
$9 = 13
(gdb) p z
$10 = {value = {lval = 140297449616832, dval = 6.931615005481985e-310, counted = 0x7f998ba5b5c0, str = 0x7f998ba5b5c0, arr = 0x7f998ba5b5c0, obj = 0x7f998ba5b5c0,
res = 0x7f998ba5b5c0, ref = 0x7f998ba5b5c0, ast = 0x7f998ba5b5c0, zv = 0x7f998ba5b5c0, ptr = 0x7f998ba5b5c0, ce = 0x7f998ba5b5c0, func = 0x7f998ba5b5c0, ww = {w1 = 2342892992,
w2 = 32665}}, u1 = {v = {type = 120 'x', type_flags = 26 '\032', const_flags = 161 '\241', reserved = 139 '\213'}, type_info = 2342591096}, u2 = {var_flags = 32665,
next = 32665, cache_slot = 32665, lineno = 32665, num_args = 32665, fe_pos = 32665, fe_iter_idx = 32665}}
(gdb) p z_keys[i]
$11 = {value = {lval = 140295106723846, dval = 6.9314992511883585e-310, counted = 0x7f9900000006, str = 0x7f9900000006, arr = 0x7f9900000006, obj = 0x7f9900000006,
res = 0x7f9900000006, ref = 0x7f9900000006, ast = 0x7f9900000006, zv = 0x7f9900000006, ptr = 0x7f9900000006, ce = 0x7f9900000006, func = 0x7f9900000006, ww = {w1 = 6,
w2 = 32665}}, u1 = {v = {type = 0 '\000', type_flags = 0 '\000', const_flags = 0 '\000', reserved = 0 '\000'}, type_info = 0}, u2 = {var_flags = 32665, next = 32665,
cache_slot = 32665, lineno = 32665, num_args = 32665, fe_pos = 32665, fe_iter_idx = 32665}}
(gdb) p response
$12 = 0x7f998ba01060 "0"
(gdb) p response_len
$13 = 1
(gdb) info args
execute_data = 0x7f998ba136e0
return_value = 0x7f998ba136b0
redis_sock = 0x7f998ba5e240
z_tab = 0x7ffd2a57b3c0
ctx = 0x7f998ba6b380
(gdb) info registers
rax 0x7f9900000006 140295106723846
rbx 0x7f998ba136e0 140297449322208
rcx 0x7ffd2a57ae80 140725313842816
rdx 0xd0 208
rsi 0x7f998ba01060 140297449246816
rdi 0x1 1
rbp 0x7ffd2a57b300 0x7ffd2a57b300
rsp 0x7ffd2a57ae50 0x7ffd2a57ae50
r8 0x7f998f35b060 140297509384288
r9 0x7f9985635a4c 140297344604748
r10 0x1 1
r11 0x7f998f120730 140297507047216
r12 0x1 1
r13 0x1114f60 17911648
r14 0x7f998ba135b0 140297449321904
r15 0x7f9980d8a8d8 140297268406488
rip 0x7f9985061949 0x7f9985061949 <redis_mbulk_reply_assoc+568>
eflags 0x10206 [ PF IF RF ]
cs 0x33 51
ss 0x2b 43
ds 0x0 0
es 0x0 0
fs 0x0 0
gs 0x0 0
(gdb) p z_keys
$14 = (zval *) 0x7f998ba6b380
(gdb) p z_keys@38
$15 = {0x7f998ba6b380, 0xd03105670, 0x7ffd2a57b340, 0x7f998503d450 <fold_this_item+73>, 0xffff8002d5a84c71, 0x7ffd2a57b3c0, 0x7f998ba5e240, 0x31130f0, 0x7f998ba136b0, 0x7f998ba136e0,
0x7ffd2a57b390, 0x7f998503d4af <redis_sock_read_multibulk_multi_reply_loop+93>, 0xc, 0x0, 0x7ffd2a57b3c0, 0x7f998ba5e240, 0x7f998ba136b0, 0x7f998ba136e0, 0x31130f0, 0x31130f0,
0x7ffd2a57b400, 0x7f998503ccdd <redis_sock_read_multibulk_pipeline_reply+67>, 0x7f998ba136e0, 0x7f998ba5e240, 0x7f998ba136b0, 0x7f998ba136e0, 0x7f998ba82818, 0x1c07,
0x7f998ba136e0, 0x7f998ba136e0, 0x7ffd2a57b460, 0x1, 0x1114f60 <executor_globals>, 0x7f998ba135b0, 0x7ffd2a57b460, 0x7f998503d319 <zim_Redis_exec+770>, 0x7f998ba136b0,
0x7f998ba136e0}
(gdb) p numElems
$16 = 38

The text was updated successfully, but these errors were encountered:

yatsukhnenko · 2016-09-23T18:43:59Z

@yushengery, could you test on the latest commit from php7 brunch?

yushengery · 2016-09-24T07:42:11Z

@yatsukhnenko
OK, I will try, however, so far as I tested, the problem still exists in the latest few weeks commit
I have collect hundreds of crash on one server, It seems that every crash was cause by multi pipeline and they have exactly the same call stack.

yushengery · 2016-09-24T09:17:56Z

@yatsukhnenko
I have tested the latest commit 5cc64fe, it still crashes the same
here is the call stack and debug info
(gdb) bt
#0 0x00007f299e4619bd in redis_mbulk_reply_assoc (execute_data=0x7f29a4e14350, return_value=0x7f29a4e14320, redis_sock=0x7f29a4e5e900, z_tab=0x7ffc10ddca00, ctx=0x7f29a4e02690)
at /usr/local/soft/php-7.0.9/ext/phpredis/library.c:1883
#1 0x00007f299e43d291 in fold_this_item (execute_data=0x7f29a4e14350, return_value=0x7f29a4e14320, item=0x320f820, redis_sock=0x7f29a4e5e900, z_tab=0x7ffc10ddca00)
at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2435
#2 0x00007f299e43d2f0 in redis_sock_read_multibulk_multi_reply_loop (execute_data=0x7f29a4e14350, return_value=0x7f29a4e14320, redis_sock=0x7f29a4e5e900, z_tab=0x7ffc10ddca00,
numElems=0) at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2448
#3 0x00007f299e43cbaf in redis_sock_read_multibulk_pipeline_reply (execute_data=0x7f29a4e14350, return_value=0x7f29a4e14320, redis_sock=0x7f29a4e5e900)
at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2272
#4 0x00007f299e43d18e in zim_Redis_exec (execute_data=0x7f29a4e14350, return_value=0x7f29a4e14320) at /usr/local/soft/php-7.0.9/ext/phpredis/redis.c:2402
#5 0x0000000000857dab in ZEND_DO_FCALL_SPEC_HANDLER () at /usr/local/soft/php-7.0.9/Zend/zend_vm_execute.h:842
#6 0x000000000081a2eb in execute_ex (ex=) at /usr/local/soft/php-7.0.9/Zend/zend_vm_execute.h:414
#7 0x00000000008635f7 in zend_execute (op_array=0x7f29a4e70000, op_array@entry=0x7f299a188a58, return_value=return_value@entry=0x7f29a4e14220)
at /usr/local/soft/php-7.0.9/Zend/zend_vm_execute.h:458
#8 0x00000000007ddf34 in zend_execute_scripts (type=type@entry=8, retval=0x7f29a4e14220, retval@entry=0x0, file_count=file_count@entry=3)
at /usr/local/soft/php-7.0.9/Zend/zend.c:1427
#9 0x0000000000782850 in php_execute_script (primary_file=primary_file@entry=0x7ffc10ddef50) at /usr/local/soft/php-7.0.9/main/main.c:2494
#10 0x000000000044055c in main (argc=, argv=) at /usr/local/soft/php-7.0.9/sapi/fpm/fpm/fpm_main.c:1968
(gdb) l 1880
1875
1876 for(i = 0; i < numElems; ++i) {
1877 response = redis_sock_read(redis_sock, &response_len TSRMLS_CC);
1878 if(response != NULL) {
1879 zval z;
1880 if(redis_unserialize(redis_sock, response, response_len, &z) == 1) {
1881 add_assoc_zval_ex(&z_multi_result, Z_STRVAL(z_keys[i]), Z_STRLEN(z_keys[i]), &z);
1882 } else {
1883 add_assoc_stringl_ex(&z_multi_result, Z_STRVAL(z_keys[i]), Z_STRLEN(z_keys[i]), response, response_len);
1884 }
(gdb) p numElems
$17 = 46
(gdb) p i
$18 = 4
(gdb) p * z_keys[0].value.str
$19 = {
gc = {
refcount = 1,
u = {
v = {
type = 6 '\006',
flags = 6 '\006',
gc_info = 0
},
type_info = 1542
}
},
h = 9223372247575703181,
len = 5,
val = "m"
}
(gdb) p * z_keys[1].value.str
$20 = {
gc = {
refcount = 1,
u = {
v = {
type = 6 '\006',
flags = 6 '\006',
gc_info = 0
},
type_info = 1542
}
},
h = 9223372043240503415,
len = 4,
val = "t"
}
(gdb) p * z_keys[2].value.str
$21 = {
gc = {
refcount = 1,
u = {
v = {
type = 6 '\006',
flags = 6 '\006',
gc_info = 0
},
type_info = 1542
}
},
h = 11739425061442757624,
len = 14,
val = "l"
}
(gdb) p * z_keys[3].value.str
$22 = {
gc = {
refcount = 1,
u = {
v = {
type = 6 '\006',
flags = 6 '\006',
gc_info = 0
},
type_info = 1542
}
},
h = 9223372037048283783,
len = 3,
val = "u"
}
(gdb) p * z_keys[4].value.str
Cannot access memory at address 0x7d22353832343333
(gdb) p * z_keys[5].value.str
$23 = {
gc = {
refcount = 1,
u = {
v = {
type = 6 '\006',
flags = 6 '\006',
gc_info = 0
},
type_info = 1542
}
},
h = 9223372247575703181,
len = 5,
val = "m"
}

yatsukhnenko · 2016-09-24T20:50:55Z

@yushengery, interesting... Could you show (gdb) p * z_keys[4]?

yushengery · 2016-09-25T03:46:40Z

@yatsukhnenko , I guess it should be p z_keys[4] , is that right?
(gdb) set print pretty on
(gdb) p z_keys[4]
$2 = {
value = {
lval = 9016827919425876787,
dval = 5.8144061260775852e+294,
counted = 0x7d22353832343333,
str = 0x7d22353832343333,
arr = 0x7d22353832343333,
obj = 0x7d22353832343333,
res = 0x7d22353832343333,
ref = 0x7d22353832343333,
ast = 0x7d22353832343333,
zv = 0x7d22353832343333,
ptr = 0x7d22353832343333,
ce = 0x7d22353832343333,
func = 0x7d22353832343333,
ww = {
w1 = 842281779,
w2 = 2099393848
}
},
u1 = {
v = {
type = 0 '\000',
type_flags = 0 '\000',
const_flags = 0 '\000',
reserved = 0 '\000'
},
type_info = 0
},
u2 = {
var_flags = 10,
next = 10,
cache_slot = 10,
lineno = 10,
num_args = 10,
fe_pos = 10,
fe_iter_idx = 10
}
}
(gdb) p i
$3 = 4
(gdb) p numElems
$4 = 46
(gdb) p z_keys[4].value.str
$5 = (zend_string *) 0x7d22353832343333
(gdb) p *z_keys[4].value.str
Cannot access memory at address 0x7d22353832343333

yatsukhnenko · 2016-09-26T06:31:06Z

@yushengery, I don't know exactly how it can happens and can't reproduce this bug.
As a suggestion could you test this patch?

diff --git a/library.c b/library.c
index e54181f..6ef48dc 100644
--- a/library.c
+++ b/library.c
@@ -1874,6 +1874,7 @@ PHP_REDIS_API int redis_mbulk_reply_assoc(INTERNAL_FUNCTION_PARAMETERS, RedisSoc
     array_init(&z_multi_result); /* pre-allocate array for multi's results. */

     for(i = 0; i < numElems; ++i) {
+        if (Z_TYPE(z_keys[i]) != IS_STRING) continue;
         response = redis_sock_read(redis_sock, &response_len TSRMLS_CC);
         if(response != NULL) {
             zval z;

yushengery · 2016-09-27T04:37:09Z

I did hmget hmset mget in the multi pipeline contex
it seems that the malloc may fail with some of the keys.

yatsukhnenko · 2016-09-27T08:14:23Z

redis_hmget_cmd

1495         // We can only handle string or long values here
1496         if ((Z_TYPE_P(z_mem) == IS_STRING && Z_STRLEN_P(z_mem) > 0)
1497             || Z_TYPE_P(z_mem) == IS_LONG)
1498         {
1499             // Copy into our member array
1500             ZVAL_DUP(&z_mems[valid], z_mem);
1501             convert_to_string(&z_mems[valid]);
1502 
1503             // Increment the member count to actually send
1504             valid++;
1505         }

It seems like we allocate some number of elements, but not all of them are valid string/long so we skip them

1515     // Sentinel so we can free this even if it's used and then we discard
1516     // the transaction manually or there is a transaction failure
1517     ZVAL_UNDEF(&z_mems[valid]);

But further we use all allocated elements without reordering

1537     *ctx     = (void*)z_mems;

yushengery · 2016-09-27T14:39:41Z

@yatsukhnenko
I guess I have found the cause of this issue, I found the response was not compatible to the request.
I set the memory_limit to be 64MB in the php.ini, I was using redis persistent connections to the server.
There may be some garbage data leaving in the stream due to the exit of last request fail to alloc memory which may crash the php-fpm.
I am trying to set the memory_limit to be 128M in my server, hoping this will prove my guess. Good Luck.

yushengery · 2016-10-01T09:55:34Z

This issue should be caused by the reason I mentioned, I changed the persistence connection the short connection , there is not any coredump more.
This issue can be closed now

yushengery closed this as completed Oct 1, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uh oh!

Many segment faults in multi-exec #960

Many segment faults in multi-exec #960

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Many segment faults in multi-exec #960

Many segment faults in multi-exec #960

Comments

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!