Bug #64827 [Fbk->NoF]: Segfault in zval_mark_grey (zend_gc.c)

Edit report at https://bugs.php.net/bug.php?id=64827&edit=1 ID: 64827 Updated by: php-bugs@lists.php.net Reported by: odoucet@php.net Summary: Segfault in zval_mark_grey (zend_gc.c) -Status: Feedback +Status: No Feedback Type: Bug Package: opcache Operating System: Linux PHP Version: 5.4.15 Assigned To: cmb Private report: N New Comment: No feedback was provided. The bug is being suspended because we assume that you are no longer experiencing the problem. If this is not the case and you are able to provide the information that was requested earlier, please do so and change the status of the bug back to "Re-Opened". Thank you. Previous Comments: ------------------------------------------------------------------------ [2020-11-03 18:06:32] cmb@php.net Does this still happen with any of the actively supported PHP versions[1]? [1] <https://www.php.net/supported-versions.php> ------------------------------------------------------------------------ [2016-06-18 05:31:40] ta-sdz at deshammer dot net Hello everybody on this long outstanding bug. I think I'm onto something there. I had this SIG11 regularly and reproducibly enough to reliably get coredumps in an application too huge to be shared publicly. Here's one backtrace of them on a 5.6.22 installation: (gdb) bt full #0 0x00007f58457a9a6d in zval_mark_grey (pz=<optimized out>) at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:420 p = 0x7f585ca80790 #1 0x00007f58457aab19 in zobj_mark_grey (obj=<optimized out>, pz=<optimized out>) at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:454 i = 0 n = 4 table = 0x7f585ca75f00 p = <optimized out> get_gc = <optimized out> #2 gc_mark_roots () at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:488 z = {value = {lval = 140015933864297, dval = 6.917706279272916e-310, str = {val = 0x7f5800003969 <Address 0x7f5800003969 out of bounds>, len = 1169556032}, ht = 0x7f5800003969, obj = {handle = 14697, handlers = 0x7f5845b60240 <std_object_handlers>}, ast = 0x7f5800003969}, refcount__gc = 1, type = 88 'X', is_ref__gc = 0 '\000'} obj = <optimized out> current = 0x7f5844a1be50 #3 gc_collect_cycles () at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:790 p = <optimized out> q = <optimized out> orig_free_list = <optimized out> orig_next_to_free = <optimized out> count = 0 #4 0x00007f58457aae02 in gc_zval_possible_root (zv=0x7f58582723d8) at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:163 newRoot = <optimized out> #5 0x00007f5845797f48 in zend_hash_destroy (ht=0x7f585ca81008) at /usr/src/debug/php-5.6.22/Zend/zend_hash.c:548 p = 0x7f585ca7ea00 q = 0x7f585ca805d8 #6 0x00007f58457b127c in zend_object_std_dtor (object=0x7f585ca7e7b8) at /usr/src/debug/php-5.6.22/Zend/zend_objects.c:44 No locals. #7 0x00007f58457b1309 in zend_objects_free_object_storage (object=0x7f585ca7e7b8) at /usr/src/debug/php-5.6.22/Zend/zend_objects.c:137 No locals. #8 0x00007f58457b75ec in zend_objects_store_del_ref_by_handle_ex (handle=14702, handlers=<optimized out>) at /usr/src/debug/php-5.6.22/Zend/zend_objects_API.c:226 __orig_bailout = 0x7ffc1fc46590 __bailout = {{__jmpbuf = {140017488351064, -2743026434694212569, 140016688292440, 140017400377624, 140016688292440, 0, -2835498401476668377, -2742977752702544857}, __mask_was_saved = 0, __saved_mask = {__val = {140017099424667, 140017103407076, 140017086683120, 206158430224, 140720841449808, 140720841449600, 13176172747737717760, 140017103407076, 140017099629640, 140720841449824, 140720841449820, 1, 140017086682768, 8, 4, 140017099310240}}}} ---Type <return> to continue, or q <return> to quit---q Quit (gdb) frame 0 #0 0x00007f58457a9a6d in zval_mark_grey (pz=<optimized out>) at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:420 420 pz = *(zval**)p->pData; (gdb) print p $1 = (Bucket *) 0x7f585ca80790 (gdb) print *(zval**) p $2 = (zval *) 0x7f585c102478 (gdb) print *(zval**) p->pData Cannot access memory at address 0x0 (gdb) print p->pData $3 = (void *) 0x0 (gdb) Now look at that! p->pData is a NULL-Pointer which should reference something. Well - nothing simplier than that - I thought - catch the NULL and be fine. But ... after catching the (p->pData==NULL) some more came up. Core was generated by `/usr/sbin/httpd -DFOREGROUND'. Program terminated with signal 11, Segmentation fault. #0 zval_mark_grey (pz=0x0) at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:422 422 if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { (gdb) print pz $1 = (zval *) 0x0 (gdb) So there is (pz==NULL) and this gave the operations on pz in line 422 the creeps. Well then - let's catch (pz==NULL) as well ... I thought again - or at least I tried. After catching (p->pData==NULL) and (pz==NULL) the SIG11 wandered into the zval_scan_black() function: Program terminated with signal 11, Segmentation fault. #0 0x00007f8e76ac4cbd in zval_scan_black (pz=<optimized out>) at /usr/src/debug/php-5.6.22/Zend/zend_gc.c:313 313 pz = *(zval**)p->pData; (gdb) print p $1 = (Bucket *) 0x7f8e8e05e1e0 (gdb) print p->pData $2 = (void *) 0x0 (gdb) print *p $3 = {h = 140250165711864, nKeyLength = 2382165776, pData = 0x0, pDataPtr = 0x0, pListNext = 0x0, pListLast = 0x7f8e8e05e3f0, pNext = 0x0, pLast = 0x0, arKey = 0x7f8e5d205fd8 "hackLanguageID"} (gdb) and so on and so on - until any loop over p which referenced p->pData or pz was enclosed with a null pointer catch. After that there were no more SIG11s. I'm fully aware that this patch should have remedied the cause of the p->pData==NULL and the pz==NULL and not the symptom but this was way over my head. As well as the part of "TODO: Maybe some logging here". Well - here's the patch which I wanted you to review and maybe add some logging to it: --- php-5.6.22/Zend/zend_gc.c 2016-05-26 03:08:57.000000000 +0200 +++ php-5.6.22-patched/Zend/zend_gc.c 2016-06-17 21:27:32.226425023 +0200 @@ -310,16 +310,25 @@ } } while (p != NULL) { - pz = *(zval**)p->pData; - if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { - pz->refcount__gc++; - } - if (GC_ZVAL_GET_COLOR(pz) != GC_BLACK) { - if (p->pListNext == NULL) { - goto tail_call; + if (p->pData != NULL) { + pz = *(zval**)p->pData; + if (pz != NULL) { + if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { + pz->refcount__gc++; + } + if (GC_ZVAL_GET_COLOR(pz) != GC_BLACK) { + if (p->pListNext == NULL) { + goto tail_call; + } else { + zval_scan_black(pz TSRMLS_CC); + } + } } else { - zval_scan_black(pz TSRMLS_CC); + /* Now this is really odd ... we've got a p->pData which references a NULL pointer */ } + } else { + /* shall we log something when encountering a p->pData == NULL */ + } p = p->pListNext; } @@ -353,12 +362,20 @@ } p = props->pListHead; while (p != NULL) { - pz = *(zval**)p->pData; - if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { - pz->refcount__gc++; - } - if (GC_ZVAL_GET_COLOR(pz) != GC_BLACK) { - zval_scan_black(pz TSRMLS_CC); + if (p->pData != NULL) { + pz = *(zval**)p->pData; + if (pz != NULL) { + if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { + pz->refcount__gc++; + } + if (GC_ZVAL_GET_COLOR(pz) != GC_BLACK) { + zval_scan_black(pz TSRMLS_CC); + } + } else { + /* pz is NULL - maybe there should be some logging? */ + } + } else { + /* p->pData is NULL - maybe there should be some logging? */ } p = p->pListNext; } @@ -417,14 +434,23 @@ } } while (p != NULL) { - pz = *(zval**)p->pData; - if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { - pz->refcount__gc--; - } - if (p->pListNext == NULL) { - goto tail_call; + if (p->pData != NULL) { + pz = *(zval**)p->pData; + if (pz != NULL) { + if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { + pz->refcount__gc--; + } + if (p->pListNext == NULL) { + goto tail_call; + } else { + zval_mark_grey(pz TSRMLS_CC); + } + } else { + /* Now this is odd - we have a valid pz and a pData which is NULL */ + + } } else { - zval_mark_grey(pz TSRMLS_CC); + /* Some logging maybe? p->pData is NULL */ } p = p->pListNext; } @@ -459,11 +485,19 @@ } p = props->pListHead; while (p != NULL) { - pz = *(zval**)p->pData; - if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { - pz->refcount__gc--; + if (p->pData != NULL) { + pz = *(zval**)p->pData; + if (pz != NULL) { + if (Z_TYPE_P(pz) != IS_ARRAY || Z_ARRVAL_P(pz) != &EG(symbol_table)) { + pz->refcount__gc--; + } + zval_mark_grey(pz TSRMLS_CC); + } else { + /* TODO: Some logging maybe? */ + } + } else { + /* TODO: Some logging maybe? */ } - zval_mark_grey(pz TSRMLS_CC); p = p->pListNext; } } ------------------------------------------------------------------------ [2015-04-21 16:01:42] justin at eblah dot com @laruence -- I saw back in 2013 where you requested access to a box where this is happening. I may be able to give you a cloned box to work with if that'd help, but I'd have to talk to some people first. Let me know if interested. ------------------------------------------------------------------------ [2015-04-21 15:56:25] justin at eblah dot com I'm also seeing this, but can't reproduce it easily. I can add an additional echo somewhere in the script, and the problem goes away, so I don't know how to reproduce it code wise. #0 zval_mark_grey (pz=0x7f2b76f7d268) at /usr/src/debug/php-5.6.8/Zend/zend_gc.c:421 #1 0x00000000005e008d in gc_mark_roots () at /usr/src/debug/php-5.6.8/Zend/zend_gc.c:501 #2 gc_collect_cycles () at /usr/src/debug/php-5.6.8/Zend/zend_gc.c:795 #3 0x00000000005e0192 in gc_zobj_possible_root (zv=<value optimized out>) at /usr/src/debug/php-5.6.8/Zend/zend_gc.c:221 #4 0x000000000063f828 in gc_zval_check_possible_root (execute_data=0x7f2b95bb87a0) at /usr/src/debug/php-5.6.8/Zend/zend_gc.h:183 #5 zend_assign_to_variable (execute_data=0x7f2b95bb87a0) at /usr/src/debug/php-5.6.8/Zend/zend_execute.c:930 #6 ZEND_ASSIGN_SPEC_CV_VAR_HANDLER (execute_data=0x7f2b95bb87a0) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:37448 #7 0x000000000062dbe8 in execute_ex (execute_data=0x7f2b95bb87a0) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:363 #8 0x00000000005af8ce in dtrace_execute_ex (execute_data=0x7f2b95bb87a0) at /usr/src/debug/php-5.6.8/Zend/zend_dtrace.c:73 #9 0x00007f2b7f5cdd4d in nr_php_execute_enabled () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:1099 #10 0x00007f2b7f5ce362 in nr_php_execute () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:1210 #11 0x000000000063e6bc in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:592 #12 0x000000000062dbe8 in execute_ex (execute_data=0x7f2b95bb8638) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:363 #13 0x00000000005af8ce in dtrace_execute_ex (execute_data=0x7f2b95bb8638) at /usr/src/debug/php-5.6.8/Zend/zend_dtrace.c:73 #14 0x00007f2b7f5cdd4d in nr_php_execute_enabled () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:1099 #15 0x00007f2b7f5ce362 in nr_php_execute () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:1210 #16 0x000000000063e6bc in zend_do_fcall_common_helper_SPEC (execute_data=<value optimized out>) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:592 #17 0x000000000062dbe8 in execute_ex (execute_data=0x7f2b95bb8448) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:363 #18 0x00000000005af8ce in dtrace_execute_ex (execute_data=0x7f2b95bb8448) at /usr/src/debug/php-5.6.8/Zend/zend_dtrace.c:73 #19 0x00007f2b7f5cdf75 in nr_php_execute_enabled () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:947 #20 0x00007f2b7f5ce362 in nr_php_execute () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:1210 #21 0x000000000062d581 in ZEND_INCLUDE_OR_EVAL_SPEC_TMP_HANDLER (execute_data=0x7f2b95bb8150) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:8390 #22 0x000000000062dbe8 in execute_ex (execute_data=0x7f2b95bb8150) at /usr/src/debug/php-5.6.8/Zend/zend_vm_execute.h:363 #23 0x00000000005af8ce in dtrace_execute_ex (execute_data=0x7f2b95bb8150) at /usr/src/debug/php-5.6.8/Zend/zend_dtrace.c:73 #24 0x00007f2b7f5cdf75 in nr_php_execute_enabled () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:947 #25 0x00007f2b7f5ce362 in nr_php_execute () at /home/hudson/slave-workspace/workspace/PHP_Release_Agent/label/centos5-64-nrcamp/agent/php_execute.c:1210 #26 0x00000000005bef5c in zend_execute_scripts (type=8, retval=0x0, file_count=3) at /usr/src/debug/php-5.6.8/Zend/zend.c:1341 #27 0x000000000055d77a in php_execute_script (primary_file=0x7fff6856ab30) at /usr/src/debug/php-5.6.8/main/main.c:2597 #28 0x0000000000665ae3 in do_cli (argc=4, argv=0x265c9d0) at /usr/src/debug/php-5.6.8/sapi/cli/php_cli.c:994 #29 0x00000000006662e8 in main (argc=4, argv=0x265c9d0) at /usr/src/debug/php-5.6.8/sapi/cli/php_cli.c:1378 ------------------------------------------------------------------------ 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=64827 -- Edit this bug report at https://bugs.php.net/bug.php?id=64827&edit=1