Edit report at https://bugs.php.net/bug.php?id=71135&edit=1
ID: 71135
Updated by: rasmus@php.net
Reported by: iquito at gmx dot net
Summary: Random memory corruption with strings
Status: Closed
Type: Bug
Package: opcache
Operating System: Debian Jessie
PHP Version: 7.0.0
Assigned To: laruence
Block user comment: N
Private report: N
New Comment:
So two very different spots in your PHP code. Kind of expected for memory corruption. The corruption
happened earlier and it is somewhat random when it actually triggers a crash. I don't suppose
you can reproduce it reliably? If you can Valgrind might be able to spot the initial corruption.
I use a this little valgrind script to do a memcheck:
#!/bin/bash
USE_ZEND_ALLOC=0 valgrind --tool=memcheck --leak-check=yes --suppressions=/home/rasmus/.suppressions
--track-origins=yes --num-callers=30 --show-reachable=yes "$@"
You can skip the suppressions, although it isn't a bad idea to run it once on a trivial
phpinfo() or hello world script and record your suppressions just to clean up the output a bit.
Then I just do: memcheck php script.php
Of course, it is unlikely to be that simple, but you can also run the entire php-fpm or httpd under
memcheck. It runs very slowly, so don't do this on a production box, of course.
Previous Comments:
------------------------------------------------------------------------
[2017-09-11 01:19:31] jjones at smugmug dot com
Thanks for the pointer to the gdbinit file. There's some nice tools in there...
Here are the results from "zbacktrace" from the two core dumps I have.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000000000b64983 in zend_inline_hash_func (len=31426464, str=0x7fcf65800001 <error: Cannot
access memory at address 0x7fcf65800001>) at
/home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_string.h:331
331 hash = ((hash << 5) + hash) + *str++;
(gdb) zbacktrace
[0x7fcf656146a0] Lib\Base->__autoload("SmugMug\Router\Img")
/var/www/www_inside/1504876151/include/setup.mgi:731
[0x7fcf65614640] spl_autoload_call("SmugMug\Router\Img") [internal function]
[0x7fff7073b0a0] ???
[0x7fcf656145a0] SmugMug\Router\Base->setup()
/var/www/www_inside/1504876151/include/classes/SmugMug/Router/Base.php:607
[0x7fcf656140e0] (main) /var/www/www_inside/1504876151/include/setup.mgi:100
[0x7fcf65614030] (main) /var/www/www_inside/1504876151/index.mg:8
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000000000bb6763 in ZEND_ECHO_SPEC_CONST_HANDLER () at
/home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:2667
2667 if (ZSTR_LEN(str) != 0) {
(gdb) zbacktrace
[0x7f8f2f415430] Lib\Spit->(main)
/var/www/www_inside/1504876151/include/legacy-pages/test/react-library/react-tools-browserify-bundle.js:1
[0x7f8f2f4153a0]
Lib\Spit->out("/include/legacy-pages/test/react-library/react-tools-browserify-bundle.js",
reference) /var/www/www_inside/1504876151/include/classes/Lib/Spit.php:39
[0x7f8f2f415300]
Lib\Spit->swallow("/include/legacy-pages/test/react-library/react-tools-browserify-bundle.js",
array(0)[0x7f8f2f415360]) /var/www/www_inside/1504876151/include/classes/Lib/Spit.php:57
[0x7f8f2f415270]
SmugMug\Spit->swallow("/include/legacy-pages/test/react-library/react-tools-browserify-bundle.js")
/var/www/www_inside/1504876151/include/classes/SmugMug/Spit.php:61
[0x7f8f2f415150] SmugMug\UI\UIExample->init(object[0x7f8f2f4151a0], array(1)[0x7f8f2f4151b0])
/var/www/www_inside/1504876151/include/classes/SmugMug/UI/UIExample.php:54
[0x7f8f2f4150e0] (main)
/var/www/www_inside/1504876151/include/legacy-pages/test/react-library/index.mg:94
[0x7f8f2f415030] (main) /var/www/www_inside/1504876151/index.mg:21
------------------------------------------------------------------------
[2017-09-10 13:25:33] rasmus@php.net
Do you get a useful zbacktrace from these cores? (See https://github.com/php/php-src/blob/PHP-7.1/.gdbinit)
------------------------------------------------------------------------
[2017-09-10 09:18:17] jjones at smugmug dot com
As for the values of the opcache restart stats from the crashes processes, I think this is what
you're asking for.
#0 0x0000000000b64983 in zend_inline_hash_func (len=31426464,
str=0x7fcf65800001 <error: Cannot access memory at address 0x7fcf65800001>)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_string.h:331
331 hash = ((hash << 5) + hash) + *str++;
(gdb) print *accel_shared_globals
$1 = {hits = 573580, misses = 94, blacklist_misses = 0, oom_restarts = 0, hash_restarts = 0,
manual_restarts = 0
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000000000bb6763 in ZEND_ECHO_SPEC_CONST_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:2667
2667 if (ZSTR_LEN(str) != 0) {
(gdb) print *accel_shared_globals
$1 = {hits = 19012587, misses = 53, blacklist_misses = 0, oom_restarts = 0, hash_restarts = 0,
manual_restarts = 0
Meaning, they were all zero at the time, in both core dumps.
------------------------------------------------------------------------
[2017-09-10 09:14:18] jjones at smugmug dot com
I captured another core dump which has different backtrace, but ultimately crashes with a SegFault
due to a string pointer is can't dereference.
#0 0x0000000000bb6763 in ZEND_ECHO_SPEC_CONST_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:2667
#1 0x0000000000ba9a6b in execute_ex (ex=0x7f8f2f415430)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:429
#2 0x0000000000c88ec8 in ZEND_INCLUDE_OR_EVAL_SPEC_TMPVAR_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:51699
#3 0x0000000000ba9a6b in execute_ex (ex=0x7f8f2f4153a0)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:429
#4 0x0000000000baec11 in ZEND_DO_FCALL_SPEC_RETVAL_USED_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:1076
#5 0x0000000000ba9a6b in execute_ex (ex=0x7f8f2f415300)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:429
#6 0x0000000000baec11 in ZEND_DO_FCALL_SPEC_RETVAL_USED_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:1076
#7 0x0000000000ba9a6b in execute_ex (ex=0x7f8f2f415270)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:429
#8 0x0000000000baec11 in ZEND_DO_FCALL_SPEC_RETVAL_USED_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:1076
#9 0x0000000000ba9a6b in execute_ex (ex=0x7f8f2f415150)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:429
#10 0x0000000000badfa4 in ZEND_DO_FCALL_SPEC_RETVAL_UNUSED_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:949
#11 0x0000000000ba9a6b in execute_ex (ex=0x7f8f2f4150e0)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:429
#12 0x0000000000c88ec8 in ZEND_INCLUDE_OR_EVAL_SPEC_TMPVAR_HANDLER ()
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:51699
#13 0x0000000000ba9a6b in execute_ex (ex=0x7f8f2f415030)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:429
#14 0x0000000000baa42b in zend_execute (op_array=0x7f8f2f4731c0, return_value=0x0)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend_vm_execute.h:474
#15 0x0000000000b0fcc1 in zend_execute_scripts (type=8, retval=0x0, file_count=3)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/Zend/zend.c:1480
#16 0x0000000000a5b290 in php_execute_script (primary_file=0x7ffc59ab28f0)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/main/main.c:2552
#17 0x0000000000cb836f in main (argc=2, argv=0x7ffc59ab2be8)
at /home/jjones/ops/ops-tools/deb-build/work/php-7.1.9/sapi/fpm/fpm/fpm_main.c:1966
some info that might be helpful...
(gdb) list 2667
2662 z = EX_CONSTANT(opline->op1);
2663
2664 if (Z_TYPE_P(z) == IS_STRING) {
2665 zend_string *str = Z_STR_P(z);
2666
2667 if (ZSTR_LEN(str) != 0) {
2668 zend_write(ZSTR_VAL(str), ZSTR_LEN(str));
2669 }
2670 } else {
2671 zend_string *str = _zval_get_string_func(z);
(gdb) print *z
$6 = {value = {lval = 140250487923552, dval = 6.9292947895499668e-310, counted = 0x7f8e9c832360, str
= 0x7f8e9c832360,
arr = 0x7f8e9c832360, obj = 0x7f8e9c832360, res = 0x7f8e9c832360, ref = 0x7f8e9c832360, ast =
0x7f8e9c832360, zv = 0x7f8e9c832360,
ptr = 0x7f8e9c832360, ce = 0x7f8e9c832360, func = 0x7f8e9c832360, ww = {w1 = 2625839968, w2 =
32654}}, u1 = {v = {type = 6 '\006',
type_flags = 0 '\000', const_flags = 0 '\000', reserved = 0
'\000'}, type_info = 6}, u2 = {next = 4294967295,
cache_slot = 4294967295, lineno = 4294967295, num_args = 4294967295, fe_pos = 4294967295,
fe_iter_idx = 4294967295,
access_flags = 4294967295, property_guard = 4294967295, extra = 4294967295}}
(gdb) print z->value->str
$7 = (zend_string *) 0x7f8e9c832360
(gdb) print *z->value->str
Cannot access memory at address 0x7f8e9c832360
------------------------------------------------------------------------
[2017-09-10 06:31:44] rasmus@php.net
Is this after a cache full event? As in, when you see this happening, what are the values of these
opcache vars in your phpinfo output?
OOM restarts
Hash keys restarts
Manual restarts
PHP 7.1.x has been running in production on a ton of heavily hit sites with at least some of them
making heavy use of memcached without ever seeing this. The ones I am involved with almost never hit
a cache reset condition, so that might be a difference.
------------------------------------------------------------------------
The remainder of the comments for this report are too long. To view
the rest of the comments, please view the bug report online at
https://bugs.php.net/bug.php?id=71135
--
Edit this bug report at https://bugs.php.net/bug.php?id=71135&edit=1