Bug #68486 [Com]: PHP SegFault zend_hash_find

Edit report at https://bugs.php.net/bug.php?id=68486&edit=1 ID: 68486 Comment by: php at bof dot de Reported by: wattwood at tcstire dot com Summary: PHP SegFault zend_hash_find Status: Open Type: Bug Package: Apache2 related Operating System: Ubuntu 14.04.1 LTS PHP Version: 5.5.19 Block user comment: N Private report: N New Comment: After more debugging, and comparing with my apache 2.2 setup, the root cause of the problem is pretty clear: Apache 2.4 no longer calls the pool cleanup php_server_context_cleanup() between the two requests on the pipelined connection. This makes the second, independant request run with the previous SG(server_context), like a subrequest - but the first request has already shut down the interpreter... With apache 2.2 there is a proper call to php_server_context_cleanup() after each request. I'm still unsure what would be the correct fix; the logic in php_handler() covers several cases, not all clear to me. Maybe somebody can clear this up: in what situation will we enter php_handler with non-NULL ctx, ctx->request_processed == 1, and r->protocol == "INCLUDED" ? Previous Comments: ------------------------------------------------------------------------ [2015-03-10 13:41:06] php at bof dot de Just ran a single step session (xdebug + opcache disabled), first breakpoint in apache SAPI php_handler line 669 (call to zend_execute_scripts, triggering on the second pipelined request), then second breakpoint in compile_file() like 584 where the call zend_stack_push(&CG(context_stack), (void *) &CG(context), sizeof(CG(context))); bombed. Stepping into zend_stack_push I find: (gdb) step zend_stack_push (stack=stack@entry=0x7fbd1b595478 <compiler_globals+696>, element=element@entry=0x7fbd1b595450 <compiler_globals+656>, size=size@entry=40) at /usr/src/phb/build/release-5.6.7-Og/php-src/Zend/zend_stack.c:34 34 { (gdb) step 35 if (stack->top >= stack->max) { /* we need to allocate more memory */ (gdb) print *stack $1 = {top = 0, max = 64, elements = 0x0} So the code thinks it does not need to allocate - and then bombs on the following assignment to stack->elements[stack->top]. Looks like CG(context_stack).max is not properly reset somehow after the previous request... ------------------------------------------------------------------------ [2015-03-10 09:22:15] php at bof dot de Happy to find this bug.... Ran into the same problems when trying to upgrade from an older openSUSE system with Apache 2.2, to a current one with Apache 2.4. PHP in both cases, is a self-built 5.6.6 (also tested with 5.6.7RC1 and an older 5.6.4) build. As soon as I tried this in production, I got, on a box with about 2000 req/min, 2-3 coredumps per minute. Trials with opcache disabled, pointed to exactly the kind of backtraces reported here. Trials with opcache enabled (normal production) almost always resulted in backtraces like this: #0 0x00007fc2c1c0a347 in i_create_execute_data_from_op_array ( nested=<optimized out>, op_array=<optimized out>) at /usr/src/phb/build/release-5.6.7-Og/php-src/Zend/zend_execute.c:1676 1676 EX(prev_execute_data) = EG(current_execute_data); (gdb) bt #0 0x00007fc2c1c0a347 in i_create_execute_data_from_op_array ( nested=<optimized out>, op_array=<optimized out>) at /usr/src/phb/build/release-5.6.7-Og/php-src/Zend/zend_execute.c:1676 #1 zend_execute (op_array=0x7fc2c06c10f8) at /usr/src/phb/build/release-5.6.7-Og/php-src/Zend/zend_vm_execute.h:388 #2 0x00007fc2c1b78bf3 in zend_execute_scripts (type=type@entry=2, retval=retval@entry=0x0, file_count=file_count@entry=1) at /usr/src/phb/build/release-5.6.7-Og/php-src/Zend/zend.c:1341 #3 0x00007fc2c1c0d672 in php_handler (r=<optimized out>) at /usr/src/phb/build/release-5.6.7-Og/php-src/sapi/apache2handler/sapi_apache2.c:669 ..... I can fully reproduce the issue now on my development system, using the echo/netcat double request from the last comment against a trivial (only one echo) test script. The following patch, against the 5.6.7RC1 sources, fixes the coredump, and results in both pipelined test script calls returning the expected result. I have not yet tested whether the patch has negative consequences, though. Here it is: diff --git a/sapi/apache2handler/sapi_apache2.c b/sapi/apache2handler/sapi_apache2.c index 088ff77..0f80aee 100644 --- a/sapi/apache2handler/sapi_apache2.c +++ b/sapi/apache2handler/sapi_apache2.c @@ -549,7 +549,7 @@ static int php_handler(request_rec *r) /* apply_config() needs r in some cases, so allocate server_context early */ ctx = SG(server_context); - if (ctx == NULL || (ctx && ctx->request_processed && !strcmp(r->protocol, "INCLUDED"))) { + if (1 || ctx == NULL || (ctx && ctx->request_processed && !strcmp(r->protocol, "INCLUDED"))) { normal: ctx = SG(server_context) = apr_pcalloc(r->pool, sizeof(*ctx)); /* register a cleanup so we clear out the SG(server_context) ------------------------------------------------------------------------ [2015-01-23 13:42:04] biggi at stefna dot is I think this is related to HTTP pipelining and Apache version 2.4 To test it, do: echo -e "GET /test.php HTTP/1.1\nHost: localhost\n\nGET /test.php HTTP/1.1\nHost: localhost\n\n"|nc localhost 80 It does not matter what is in test.php, it can be empty. Note that it does not always segfault. But if test.php outputs something, only the first output is delivered, empty on the second one. I've tested this on php versions 5.4.36, 5.5.1, 5.5.20 and 5.6.4 with version 2.2.29, 2.4.2 and 2.4.10 of apache. Tested with clean compile of both apache and php (on ubuntu 14.04). php configure: './configure' '--prefix=/tmp/testing/php5' '--with-apxs2=/tmp/testing/apache2/bin/apxs' '--disable-all' Segfaults for all tested version of php for apache 2.4, but never for 2.2.29. Also, 2.2.29 outputs all pipelined requests. Now, I did some digging and I guess the problem is in php_handler function in sapi_apache2.c: https://github.com/php/php-src/blob/PHP-5.5.20/sapi/apache2handler/sapi_apache2.c#L536 The server_context is reused (parent_req is found), which ends up with a corrupt zend_file_handle zfd (in line 669). Note that php_server_context_cleanup is never called. I assume the server_context should NOT be used again for these kind of requests. Hopefully this helps. I am getting a lot of segfaults these days. Seems that HTTP pipelining is enabled for safari on iOS devices. I am also seeing some "PHP Fatal Error Allowed memory size of 268435456 bytes exhausted (tried to allocate 22455254144 bytes)". This definitely relates to this problem, and probably something that can happen if there is no segfault. ------------------------------------------------------------------------ [2014-12-19 08:08:56] rajan dot nagarajan at innogames dot com I have the same segfault, PHP 5.5.19 Os Debian GNU gdb (GDB) 7.4.1-debian Copyright (C) 2012 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-linux-gnu". For bug reporting instructions, please see: <http://www.gnu.org/software/gdb/bugs/>... Reading symbols from /usr/bin/php...Reading symbols from /usr/lib/debug/usr/bin/php5...done. done. [New LWP 26995] warning: Can't read pathname for load map: Input/output error. [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `php test.php'. Program terminated with signal 11, Segmentation fault. #0 0x00000000006dfe18 in zend_hash_quick_find (ht=0x7fe72b0396b0, arKey=arKey@entry=0x7fe734bdeb00 "isdirty", nKeyLength=nKeyLength@entry=8, h=7572512272371981, pData=0x7fff6c1bb7e8) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_hash.c:950 950 /usr/src/php5.5/source/dotdeb-php5/Zend/zend_hash.c: No such file or directory. (gdb) bt #0 0x00000000006dfe18 in zend_hash_quick_find (ht=0x7fe72b0396b0, arKey=arKey@entry=0x7fe734bdeb00 "isdirty", nKeyLength=nKeyLength@entry=8, h=7572512272371981, pData=0x7fff6c1bb7e8) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_hash.c:950 #1 0x00000000006f88f9 in zend_std_get_method (object_ptr=<optimized out>, method_name=0x7fe734bdeab0 "isDirty", method_len=7, key=0x7fe72afefc70) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_object_handlers.c:1027 #2 0x0000000000708511 in ZEND_INIT_METHOD_CALL_SPEC_VAR_CONST_HANDLER (execute_data=0x7fe734c5e530) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_vm_execute.h:15346 #3 0x0000000000740308 in execute_ex (execute_data=0x7fe734c5e530) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_vm_execute.h:363 #4 0x00000000006c0add in dtrace_execute_ex (execute_data=<optimized out>) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_dtrace.c:73 #5 0x0000000000780866 in zend_do_fcall_common_helper_SPEC (execute_data=0x7fe734c5e128) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_vm_execute.h:584 #6 0x0000000000740308 in execute_ex (execute_data=0x7fe734c5e128) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_vm_execute.h:363 #7 0x00000000006c0add in dtrace_execute_ex (execute_data=<optimized out>) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_dtrace.c:73 #8 0x00000000006c2df1 in zend_call_function (fci=fci@entry=0x7fff6c1bbc70, fci_cache=0x0, fci_cache@entry=0x7fff6c1bbc40) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_execute_API.c:937 #9 0x00000000006e86c5 in zend_call_method (object_pp=object_pp@entry=0x7fff6c1bbd28, obj_ce=<optimized out>, fn_proxy=fn_proxy@entry=0x7fff6c1bbd20, function_name=function_name@entry=0xb35eb0 "__destruct", function_name_len=function_name_len@entry=10, retval_ptr_ptr=retval_ptr_ptr@entry=0x0, param_count=param_count@entry=0, arg1=arg1@entry=0x0, arg2=arg2@entry=0x0) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_interfaces.c:97 #10 0x00000000006f3b12 in zend_objects_destroy_object (object=0x7fe72af714c8, handle=<optimized out>) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_objects.c:123 #11 0x00000000006f9b50 in zend_objects_store_del_ref_by_handle_ex (handle=40, handlers=<optimized out>) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_objects_API.c:212 #12 0x00000000006f9b93 in zend_objects_store_del_ref (zobject=0x2a2d188) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_objects_API.c:178 #13 0x00000000006c0e20 in _zval_dtor (zvalue=0x2a2d188) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_variables.h:35 #14 i_zval_ptr_dtor (zval_ptr=0x2a2d188) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_execute.h:81 #15 _zval_ptr_dtor (zval_ptr=<optimized out>) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_execute_API.c:426 #16 0x00000000006f3c07 in zend_object_std_dtor (object=0x2c76de8) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_objects.c:54 #17 0x00000000006f3c39 in zend_objects_free_object_storage (object=0x2c76de8) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_objects.c:137 #18 0x00000000006f96c6 in zend_objects_store_free_object_storage (objects=objects@entry=0xea65e0) at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_objects_API.c:97 #19 0x00000000006c1473 in shutdown_executor () at /usr/src/php5.5/source/dotdeb-php5/Zend/zend_execute_API.c:293 #20 0x00000000006d0e85 in zend_deactivate () at /usr/src/php5.5/source/dotdeb-php5/Zend/zend.c:949 #21 0x000000000066f13a in php_request_shutdown (dummy=dummy@entry=0x0) at /usr/src/php5.5/source/dotdeb-php5/main/main.c:1808 #22 0x0000000000782b88 in do_cli (argc=2, argv=0x24af1b0) at /usr/src/php5.5/source/dotdeb-php5/sapi/cli/php_cli.c:1177 #23 0x000000000043236f in main (argc=2, argv=0x24af1b0) at /usr/src/php5.5/source/dotdeb-php5/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=68486 -- Edit this bug report at https://bugs.php.net/bug.php?id=68486&edit=1